linux1394-devel

[PATCH v2] firewire: core: send bus reset promptly on gap count error

[Adam G. <ad...@po...>]

If we are bus manager and the bus has inconsistent gap counts, send a 
bus reset immediately instead of trying to read the root node's config 
ROM first. Otherwise, we could spend a lot of time trying to read the 
config ROM but never succeeding.

This eliminates a 50+ second delay before the FireWire bus is usable after 
a newly connected device is powered on in certain circumstances.

The delay occurs if a gap count inconsistency occurs, we are not the root 
node, and we become bus manager. One scenario that causes this is with a TI 
XIO2213B OHCI, the first time a Sony DSR-25 is powered on after being 
connected to the FireWire cable. In this configuration, the Linux box will 
not receive the initial PHY configuration packet sent by the DSR-25 as IRM, 
resulting in the DSR-25 having a gap count of 44 while the Linux box has a 
gap count of 63.

FireWire devices have a gap count parameter, which is set to 63 on power-up 
and can be changed with a PHY configuration packet. This determines the 
duration of the subaction and arbitration gaps. For reliable communication, 
all nodes on a FireWire bus must have the same gap count.

A node may have zero or more of the following roles: root node, bus manager 
(BM), isochronous resource manager (IRM), and cycle master. Unless a root 
node was forced with a PHY configuration packet, any node might become root 
node after a bus reset. Only the root node can become cycle master. If the 
root node is not cycle master capable, the BM or IRM should force a change 
of root node.

After a bus reset, each node sends a self-ID packet, which contains its 
current gap count. A single bus reset does not change the gap count, but 
two bus resets in a row will set the gap count to 63. Because a consistent 
gap count is required for reliable communication, IEEE 1394a-2000 requires 
that the bus manager generate a bus reset if it detects that the gap count 
is inconsistent.

When the gap count is inconsistent, build_tree() will notice this after the 
self identification process. It will set card->gap_count to the invalid 
value 0. If we become bus master, this will force bm_work() to send a bus 
reset when it performs gap count optimization.

After a bus reset, there is no bus manager. We will almost always try to 
become bus manager. Once we become bus manager, we will first determine 
whether the root node is cycle master capable. Then, we will determine if 
the gap count should be changed. If either the root node or the gap count 
should be changed, we will generate a bus reset.

To determine if the root node is cycle master capable, we read its 
configuration ROM. bm_work() will wait until we have finished trying to 
read the configuration ROM.

However, an inconsistent gap count can make this take a long time. 
read_config_rom() will read the first few quadlets from the config ROM. Due 
to the gap count inconsistency, eventually one of the reads will time out. 
When read_config_rom() fails, fw_device_init() calls it again until 
MAX_RETRIES is reached. This takes 50+ seconds.

Once we give up trying to read the configuration ROM, bm_work() will wake 
up, assume that the root node is not cycle master capable, and do a bus 
reset. Hopefully, this will resolve the gap count inconsistency.

This change makes bm_work() check for an inconsistent gap count before 
waiting for the root node's configuration ROM. If the gap count is 
inconsistent, bm_work() will immediately do a bus reset. This eliminates 
the 50+ second delay and rapidly brings the bus to a working state.

I considered that if the gap count is inconsistent, a PHY configuration 
packet might not be successful, so it could be desirable to skip the PHY 
configuration packet before the bus reset in this case. However, IEEE 
1394a-2000 and IEEE 1394-2008 say that the bus manager may transmit a PHY 
configuration packet before a bus reset when correcting a gap count error. 
Since the standard endorses this, I decided it's safe to retain the PHY 
configuration packet transmission.

Normally, after a topology change, we will reset the bus a maximum of 5 
times to change the root node and perform gap count optimization. However, 
if there is a gap count inconsistency, we must always generate a bus reset. 
Otherwise the gap count inconsistency will persist and communication will 
be unreliable. For that reason, if there is a gap count inconstency, we 
generate a bus reset even if we already reached the 5 reset limit.

Signed-off-by: Adam Goldman <ad...@po...>
Link: https://sourceforge.net/p/linux1394/mailman/message/58727806/
---

--- linux-source-6.1.orig/drivers/firewire/core-card.c	2023-09-23 02:11:13.000000000 -0700
+++ linux-source-6.1/drivers/firewire/core-card.c	2024-02-04 20:24:53.000000000 -0800
@@ -429,7 +429,23 @@
 	 */
 	card->bm_generation = generation;
 
-	if (root_device == NULL) {
+	if (card->gap_count == 0) {
+		/* 
+		 * If self IDs have inconsistent gap counts, do a
+		 * bus reset ASAP. The config rom read might never
+		 * complete, so don't wait for it. However, still
+		 * send a PHY configuration packet prior to the
+		 * bus reset. The PHY configuration packet might
+		 * fail, but 1394-2008 8.4.5.2 explicitly permits
+		 * it in this case, so it should be safe to try.
+		 */
+		new_root_id = local_id;
+		/*
+		 * We must always send a bus reset if the gap count
+		 * is inconsistent, so bypass the 5-reset limit.
+		 */
+		card->bm_retries = 0;
+	} else if (root_device == NULL) {
 		/*
 		 * Either link_on is false, or we failed to read the
 		 * config rom.  In either case, pick another root.

Re: [PATCH] firewire: core: send bus reset promptly on gap count error

[Takashi S. <o-t...@sa...>]

Hi,

On Sun, Feb 4, 2024, at 15:22, Adam Goldman wrote:
> Is the following description acceptable?
>
> If we are bus manager and the bus has inconsistent gap counts, send a bus 
> reset immediately instead of trying to read the root node's config ROM 
> first. Otherwise, we could spend a lot of time trying to read the config 
> ROM but never succeeding.
>
> This eliminates a 50+ second delay before the FireWire bus is usable after 
> a newly connected device is powered on in certain circumstances.
>
> The delay occurs if a gap count inconsistency occurs, we are not the root 
> node, and we become bus manager. One scenario that causes this is with a TI 
> XIO2213B OHCI, the first time a Sony DSR-25 is powered on after being 
> connected to the FireWire cable. In this configuration, the Linux box will 
> not receive the initial PHY configuration packet sent by the DSR-25 as IRM, 
> resulting in the DSR-25 having a gap count of 44 while the Linux box has a 
> gap count of 63.
>
> FireWire devices have a gap count parameter, which is set to 63 on power-up 
> and can be changed with a PHY configuration packet. This determines the 
> duration of the subaction and arbitration gaps. For reliable communication, 
> all nodes on a FireWire bus must have the same gap count.
>
> A node may have one or more of the following roles: root node, bus manager 
> (BM), isochronous resource manager (IRM), and cycle master. Unless a root 
> node was forced with a PHY configuration packet, any node might become root 
> node after a bus reset. Only the root node can become cycle master. If the 
> root node is not cycle master capable, the BM or IRM should force a change 
> of root node.
>
> After a bus reset, each node sends a self-ID packet, which contains its 
> current gap count. A single bus reset does not change the gap count, but 
> two bus resets in a row will set the gap count to 63. Because a consistent 
> gap count is required for reliable communication, IEEE 1394a-2000 requires 
> that the bus manager generate a bus reset if it detects that the gap count 
> is inconsistent.
>
> When the gap count is inconsistent, build_tree() will notice this after the 
> self identification process. It will set card->gap_count to the invalid 
> value 0. If we become bus master, this will force bm_work() to send a bus 
> reset when it performs gap count optimization.
>
> After a bus reset, there is no bus manager. We will almost always try to 
> become bus manager. Once we become bus manager, we will first determine 
> whether the root node is cycle master capable. Then, we will determine if 
> the gap count should be changed. If either the root node or the gap count 
> should be changed, we will generate a bus reset.
>
> To determine if the root node is cycle master capable, we read its 
> configuration ROM. bm_work() will wait until we have finished trying to 
> read the configuration ROM.
>
> However, an inconsistent gap count can make this take a long time. 
> read_config_rom() will read the first few quadlets from the config ROM. Due 
> to the gap count inconsistency, eventually one of the reads will time out. 
> When read_config_rom() fails, fw_device_init() calls it again until 
> MAX_RETRIES is reached. This takes 50+ seconds.
>
> Once we give up trying to read the configuration ROM, bm_work() will wake 
> up, assume that the root node is not cycle master capable, and do a bus 
> reset. Hopefully, this will resolve the gap count inconsistency.
>
> This change makes bm_work() check for an inconsistent gap count before 
> waiting for the root node's configuration ROM. If the gap count is 
> inconsistent, bm_work() will immediately do a bus reset. This eliminates 
> the 50+ second delay and rapidly brings the bus to a working state.
>
> I considered that if the gap count is inconsistent, a PHY configuration 
> packet might not be successful, so it could be desirable to skip the PHY 
> configuration packet before the bus reset in this case. However, IEEE 
> 1394a-2000 and IEEE 1394-2008 say that the bus manager may transmit a PHY 
> configuration packet before a bus reset when correcting a gap count error. 
> Since the standard endorses this, I decided it's safe to retain the PHY 
> configuration packet transmission.
>
> Normally, after a topology change, we will reset the bus a maximum of 5 
> times to change the root node and perform gap count optimization. However, 
> if there is a gap count inconsistency, we must always generate a bus reset. 
> Otherwise the gap count inconsistency will persist and communication will 
> be unreliable. For that reason, if there is a gap count inconstency, we 
> generate a bus reset even if we already reached the 5 reset limit.
>
> -- Adam

It looks preferable in this case, I think. We are going to change the part
of fundamentals in this software stack, thus the longer description is
inevitable.

I think it preferable as well to add code comment about your judge to
retain sending PHY configuration packet in the case. Additionally, it
is helpful to add code comment about "bm_retries=0".


Thanks.


Takashi Sakamoto

Re: [PATCH] firewire: core: send bus reset promptly on gap count error

[Adam G. <ad...@po...>]

Hi,

On Wed, Jan 31, 2024 at 11:27:14PM +0900, Takashi Sakamoto wrote:
> I'd like to apply your patch for v6.9 kernel, while the patch
> description is not suffice, as I address. I'm sorry to ask you more
> work, but would I ask you to repost your patch with any detail
> description? The description should include enough information for
> developers inner/outer this subsystem to understand its background
> and intention.

Is the following description acceptable?

If we are bus manager and the bus has inconsistent gap counts, send a bus 
reset immediately instead of trying to read the root node's config ROM 
first. Otherwise, we could spend a lot of time trying to read the config 
ROM but never succeeding.

This eliminates a 50+ second delay before the FireWire bus is usable after 
a newly connected device is powered on in certain circumstances.

The delay occurs if a gap count inconsistency occurs, we are not the root 
node, and we become bus manager. One scenario that causes this is with a TI 
XIO2213B OHCI, the first time a Sony DSR-25 is powered on after being 
connected to the FireWire cable. In this configuration, the Linux box will 
not receive the initial PHY configuration packet sent by the DSR-25 as IRM, 
resulting in the DSR-25 having a gap count of 44 while the Linux box has a 
gap count of 63.

FireWire devices have a gap count parameter, which is set to 63 on power-up 
and can be changed with a PHY configuration packet. This determines the 
duration of the subaction and arbitration gaps. For reliable communication, 
all nodes on a FireWire bus must have the same gap count.

A node may have one or more of the following roles: root node, bus manager 
(BM), isochronous resource manager (IRM), and cycle master. Unless a root 
node was forced with a PHY configuration packet, any node might become root 
node after a bus reset. Only the root node can become cycle master. If the 
root node is not cycle master capable, the BM or IRM should force a change 
of root node.

After a bus reset, each node sends a self-ID packet, which contains its 
current gap count. A single bus reset does not change the gap count, but 
two bus resets in a row will set the gap count to 63. Because a consistent 
gap count is required for reliable communication, IEEE 1394a-2000 requires 
that the bus manager generate a bus reset if it detects that the gap count 
is inconsistent.

When the gap count is inconsistent, build_tree() will notice this after the 
self identification process. It will set card->gap_count to the invalid 
value 0. If we become bus master, this will force bm_work() to send a bus 
reset when it performs gap count optimization.

After a bus reset, there is no bus manager. We will almost always try to 
become bus manager. Once we become bus manager, we will first determine 
whether the root node is cycle master capable. Then, we will determine if 
the gap count should be changed. If either the root node or the gap count 
should be changed, we will generate a bus reset.

To determine if the root node is cycle master capable, we read its 
configuration ROM. bm_work() will wait until we have finished trying to 
read the configuration ROM.

However, an inconsistent gap count can make this take a long time. 
read_config_rom() will read the first few quadlets from the config ROM. Due 
to the gap count inconsistency, eventually one of the reads will time out. 
When read_config_rom() fails, fw_device_init() calls it again until 
MAX_RETRIES is reached. This takes 50+ seconds.

Once we give up trying to read the configuration ROM, bm_work() will wake 
up, assume that the root node is not cycle master capable, and do a bus 
reset. Hopefully, this will resolve the gap count inconsistency.

This change makes bm_work() check for an inconsistent gap count before 
waiting for the root node's configuration ROM. If the gap count is 
inconsistent, bm_work() will immediately do a bus reset. This eliminates 
the 50+ second delay and rapidly brings the bus to a working state.

I considered that if the gap count is inconsistent, a PHY configuration 
packet might not be successful, so it could be desirable to skip the PHY 
configuration packet before the bus reset in this case. However, IEEE 
1394a-2000 and IEEE 1394-2008 say that the bus manager may transmit a PHY 
configuration packet before a bus reset when correcting a gap count error. 
Since the standard endorses this, I decided it's safe to retain the PHY 
configuration packet transmission.

Normally, after a topology change, we will reset the bus a maximum of 5 
times to change the root node and perform gap count optimization. However, 
if there is a gap count inconsistency, we must always generate a bus reset. 
Otherwise the gap count inconsistency will persist and communication will 
be unreliable. For that reason, if there is a gap count inconstency, we 
generate a bus reset even if we already reached the 5 reset limit.

-- Adam

Re: [PATCH] firewire: core: send bus reset promptly on gap count error

[Takashi S. <o-t...@sa...>]

Hi,

I'm sorry to be late for reply.

On Sat, Jan 27, 2024 at 03:13:45AM -0800, Adam Goldman wrote:
> Hi,
> 
> On Sat, Jan 27, 2024 at 05:37:30PM +0900, Takashi Sakamoto wrote:
> > On Tue, Jan 23, 2024 at 12:11:40AM -0800, Adam Goldman wrote:
> > > If we are bus manager and the bus has inconsistent gap counts, send a 
> > > bus reset immediately instead of trying to read the root node's config 
> > > ROM first. Otherwise, we could spend a lot of time trying to read the 
> > > config ROM but never succeeding.
> > > 
> > > This eliminates a 50+ second delay before the FireWire bus is usable 
> > > after a newly connected device is powered on in certain circumstances.
> > 
> > At first, would I request you to explain about the certain
> > circumstances in the patch comment? It is really helpful to understand
> > the change itself.
> 
> The delay occurs if a gap count inconsistency occurs, we are not the 
> root node, and we become bus manager. One scenario that causes this is 
> with a TI XIO2213B OHCI, the first time a Sony DSR-25 is powered on 
> after being connected to the FireWire cable.
> 
> > > Link: https://sourceforge.net/p/linux1394/mailman/message/58727806/
> 
> This link has a longer description and kernel logs.
 
Of course, I've already read your post in the last week. Yes, you did
enough investigation. However, in the review process, you need to post
patches with sufficient description.
 
> > > --- linux-source-6.1.orig/drivers/firewire/core-card.c	2023-09-23 02:11:13.000000000 -0700
> > > +++ linux-source-6.1/drivers/firewire/core-card.c	2024-01-22 04:23:06.000000000 -0800
> > > @@ -435,6 +435,16 @@
> > >  		 * config rom.  In either case, pick another root.
> > >  		 */
> > >  		new_root_id = local_id;
> > > +	} else if (card->gap_count == 0) {
> > > +		/* 
> > > +		 * If self IDs have inconsistent gap counts, do a
> > > +		 * bus reset ASAP. The config rom read might never
> > > +		 * complete, so don't wait for it. However, still
> > > +		 * send a PHY configuration packet prior to the bus
> > > +		 * reset, as permitted by IEEE 1394-2008 8.4.5.2.
> > > +		 */
> > > +		new_root_id = local_id;
> > > +		card->bm_retries = 0;
> > >  	} else if (!root_device_is_running) {
> > >  		/*
> > > 		 * If we haven't probed this device yet, bail out now
> > 
> > Next, after the condition branches, we can see below lines:
> > 
> > ```
> > 	/*
> > 	 * Finally, figure out if we should do a reset or not.  If we have
> > 	 * done less than 5 resets with the same physical topology and we
> > 	 * have either a new root or a new gap count setting, let's do it.
> > 	 */
> > 
> > 	if (card->bm_retries++ < 5 &&
> > 	    (card->gap_count != gap_count || new_root_id != root_id))
> > 		do_reset = true;
> > ```
> > 
> > When the value of "card->gap_count" is zero, it would hit the condition of
> > "card->gap_count != gap_count". I think the transmission of phy config
> > packet and scheduling of short bus reset would be done, regardless of the
> > change. Would I ask the main intention to the additional branch?
> 
> Without the additional branch, the !root_device_is_running branch will 
> be taken (because the root node's config ROM hasn't been read yet), and 
> bm_work will go to sleep. Eventually we will give up trying to read the 
> config ROM, the root_device==NULL branch will be taken, and the bus 
> reset will be done. The additional branch eliminates waiting for the 
> config ROM read when gap_count is zero.
> 
> Here is the full sequence of events:
> 
> 1. Bus reset occurs due to newly active device.
> 
> 2. Self identification process completes. We are not root node. Gap 
> counts are inconsistent.
> 
> 3. build_tree() notices the gap count error and sets gap_count to 0:
> 
> > 		/*
> > 		 * If PHYs report different gap counts, set an invalid count
> > 		 * which will force a gap count reconfiguration and a reset.
> > 		 */
> > 		if (SELF_ID_GAP_COUNT(q) != gap_count)
> > 			gap_count = 0;
> 
> 4. bm_work() starts and makes us bus manager:
> 
> > 		rcode = fw_run_transaction(card, TCODE_LOCK_COMPARE_SWAP,
> > 				irm_id, generation, SCODE_100,
> > 				CSR_REGISTER_BASE + CSR_BUS_MANAGER_ID,
> > 				transaction_data, 8);
> 
> 5. read_config_rom() starts reading the root node's config ROM.
> 
> 6. bm_work() wants to know if the root node is cycle master capable. If 
> the root node is cycle master capable, we will leave it as the root 
> node. Otherwise, we will make ourself the root node. To determine if the 
> root node is cycle master capable, we must wait until its config ROM has 
> been read:
> 
> > 	} else if (!root_device_is_running) {
> > 		/*
> > 		 * If we haven't probed this device yet, bail out now
> > 		 * and let's try again once that's done.
> > 		 */
> > 		spin_unlock_irq(&card->lock);
> > 		goto out;
> 
> 7a. Without the patch: read_config_rom() reads the first few quadlets 
> from the config ROM. Due to the gap count inconsistency, eventually one 
> of the reads times out. When read_config_rom() fails, fw_device_init() 
> calls it again until MAX_RETRIES is reached. This takes 50+ seconds.
> 
> 8a. bm_work() sees that we have given up trying to read the config ROM. 
> It makes us the root node and does a bus reset:
> 
> > 	if (root_device == NULL) {
> > 		/*
> > 		 * Either link_on is false, or we failed to read the
> > 		 * config rom.  In either case, pick another root.
> > 		 */
> > 		new_root_id = local_id;
> > ...
> > 	if (card->bm_retries++ < 5 &&
> > 	    (card->gap_count != gap_count || new_root_id != root_id))
> > 		do_reset = true;
> 
> 7b. With the patch: Because of the gap count inconsistency, bm_work() 
> does not wait for the config ROM to be read. It makes us the root node 
> and does a bus reset immediately:
> 
> > 	} else if (card->gap_count == 0) {
> > 		/*
> > 		 * If self IDs have inconsistent gap counts, do a
> > 		 * bus reset ASAP. The config rom read might never
> > 		 * complete, so don't wait for it. However, still
> > 		 * send a PHY configuration packet prior to the
> > 		 * bus reset, as permitted by 1394-2008 8.4.5.2.
> > 		 */
> > 		new_root_id = local_id;
> > 		card->bm_retries = 0;
> > ...
> > 	if (card->bm_retries++ < 5 &&
> > 	    (card->gap_count != gap_count || new_root_id != root_id))
> > 		do_reset = true;

Thanks for the detail.

The mismatch of gap count can be detected in the firstworkqueue context
(bus_reset_work()) in 'driver/firewire/ohci.c', so I investigated more
quick way to reset the bus, however your change looks better than it.

I'd like to apply your patch for v6.9 kernel, while the patch
description is not suffice, as I address. I'm sorry to ask you more
work, but would I ask you to repost your patch with any detail
description? The description should include enough information for
developers inner/outer this subsystem to understand its background
and intention.


Thanks

Takashi Sakamoto

Re: [PATCH] firewire: core: mask previous entry's type bits when looking for leaf

[Takashi S. <o-t...@sa...>]

Hi,

On Fri, Jan 26, 2024 at 08:53:42PM -0800, Adam Goldman wrote:
> On Fri, Jan 26, 2024 at 09:19:17PM +0900, Takashi Sakamoto wrote:
> > I think we can handle the quirk of configuration ROM without changing
> > the kernel API. Would you test the following patch? (not tested in my
> > side).
> > 
> > ======== 8< --------
> > 
> > >From 83bf1e04d308ea89c76c64e3168b9701f9d9191b Mon Sep 17 00:00:00 2001
> > From: Takashi Sakamoto <o-t...@sa...>
> > Date: Fri, 26 Jan 2024 20:37:21 +0900
> > Subject: [PATCH] firewire: search descriptor leaf just after vendor directory
> >  entry in root directory
> 
> Hi Takashi,
> 
> I tested your patch with the DVMC-DA1. I also tested it with another 
> device with normal placement of the leaf entry. In both cases, it works.

Thanks for your test. I reposted the patch in the series of changes for
v6.8-rc3[1].

The behaviour change of kernel API is not preferable within the same
version of kernel once the release candidates is public, while we need to
handle it as the series of changes to support the legacy layout of
configuration ROM. So I'll apply my version to for-linus branch and send
it to him.

Anyway thanks for your work and suggestion.

[1] https://lore.kernel.org/lkml/202...@sa.../


Thanks

Takashi Sakamoto

[PATCH 1/2] firewire: core: correct documentation of fw_csr_string() kernel API

[Takashi S. <o-t...@sa...>]

Against its current description, the kernel API can accepts all types of
directory entries.

This commit corrects the documentation.

Cc: st...@vg...
Fixes: 3c2c58cb33b3 ("firewire: core: fw_csr_string addendum")
Signed-off-by: Takashi Sakamoto <o-t...@sa...>
---
 drivers/firewire/core-device.c | 7 +++----
 1 file changed, 3 insertions(+), 4 deletions(-)

diff --git a/drivers/firewire/core-device.c b/drivers/firewire/core-device.c
index 0547253d16fe..e4cb5106fb7d 100644
--- a/drivers/firewire/core-device.c
+++ b/drivers/firewire/core-device.c
@@ -118,10 +118,9 @@ static int textual_leaf_to_string(const u32 *block, char *buf, size_t size)
  * @buf:	where to put the string
  * @size:	size of @buf, in bytes
  *
- * The string is taken from a minimal ASCII text descriptor leaf after
- * the immediate entry with @key.  The string is zero-terminated.
- * An overlong string is silently truncated such that it and the
- * zero byte fit into @size.
+ * The string is taken from a minimal ASCII text descriptor leaf just after the entry with the
+ * @key. The string is zero-terminated. An overlong string is silently truncated such that it
+ * and the zero byte fit into @size.
  *
  * Returns strlen(buf) or a negative error code.
  */
-- 
2.40.1

[PATCH 2/2] firewire: core: search descriptor leaf just after vendor directory entry in root directory

[Takashi S. <o-t...@sa...>]

It appears that Sony DVMC-DA1 has a quirk that the descriptor leaf entry
locates just after the vendor directory entry in root directory. This is
not conformant to the legacy layout of configuration ROM described in
Configuration ROM for AV/C Devices 1.0 (1394 Trading Association, Dec 2000,
TA Document 1999027).

This commit changes current implementation to parse configuration ROM for
device attributes so that the descriptor leaf entry can be detected for
the vendor name.

$ config-rom-pretty-printer < Sony-DVMC-DA1.img
               ROM header and bus information block
               -----------------------------------------------------------------
1024  041ee7fb  bus_info_length 4, crc_length 30, crc 59387
1028  31333934  bus_name "1394"
1032  e0644000  irmc 1, cmc 1, isc 1, bmc 0, cyc_clk_acc 100, max_rec 4 (32)
1036  08004603  company_id 080046     |
1040  0014193c  device_id 12886219068  | EUI-64 576537731003586876

               root directory
               -----------------------------------------------------------------
1044  0006b681  directory_length 6, crc 46721
1048  03080046  vendor
1052  0c0083c0  node capabilities: per IEEE 1394
1056  8d00000a  --> eui-64 leaf at 1096
1060  d1000003  --> unit directory at 1072
1064  c3000005  --> vendor directory at 1084
1068  8100000a  --> descriptor leaf at 1108

               unit directory at 1072
               -----------------------------------------------------------------
1072  0002cdbf  directory_length 2, crc 52671
1076  1200a02d  specifier id
1080  13010000  version

               vendor directory at 1084
               -----------------------------------------------------------------
1084  00020cfe  directory_length 2, crc 3326
1088  17fa0000  model
1092  81000008  --> descriptor leaf at 1124

               eui-64 leaf at 1096
               -----------------------------------------------------------------
1096  0002c66e  leaf_length 2, crc 50798
1100  08004603  company_id 080046     |
1104  0014193c  device_id 12886219068  | EUI-64 576537731003586876

               descriptor leaf at 1108
               -----------------------------------------------------------------
1108  00039e26  leaf_length 3, crc 40486
1112  00000000  textual descriptor
1116  00000000  minimal ASCII
1120  536f6e79  "Sony"

               descriptor leaf at 1124
               -----------------------------------------------------------------
1124  0005001d  leaf_length 5, crc 29
1128  00000000  textual descriptor
1132  00000000  minimal ASCII
1136  44564d43  "DVMC"
1140  2d444131  "-DA1"
1144  00000000

Suggested-by: Adam Goldman <ad...@po...>
Signed-off-by: Takashi Sakamoto <o-t...@sa...>
---
 drivers/firewire/core-device.c | 11 ++++++++++-
 1 file changed, 10 insertions(+), 1 deletion(-)

diff --git a/drivers/firewire/core-device.c b/drivers/firewire/core-device.c
index e4cb5106fb7d..7d3346b3a2bf 100644
--- a/drivers/firewire/core-device.c
+++ b/drivers/firewire/core-device.c
@@ -367,8 +367,17 @@ static ssize_t show_text_leaf(struct device *dev,
 	for (i = 0; i < ARRAY_SIZE(directories) && !!directories[i]; ++i) {
 		int result = fw_csr_string(directories[i], attr->key, buf, bufsize);
 		// Detected.
-		if (result >= 0)
+		if (result >= 0) {
 			ret = result;
+		} else if (i == 0 && attr->key == CSR_VENDOR) {
+			// Sony DVMC-DA1 has configuration ROM such that the descriptor leaf entry
+			// in the root directory follows to the directory entry for vendor ID
+			// instead of the immediate value for vendor ID.
+			result = fw_csr_string(directories[i], CSR_DIRECTORY | attr->key, buf,
+					       bufsize);
+			if (result >= 0)
+				ret = result;
+		}
 	}
 
 	if (ret >= 0) {
-- 
2.40.1

[PATCH 0/2] firewire: core: optimization for the quirk of Sony DVMC-DA1

[Takashi S. <o-t...@sa...>]

Hi,

A quirk was reported that Sony DVMC-DA1 has a quirk in its configuration
ROM[1]. It has the legacy layout of configuration ROM[2] with the quirk
that the descriptor leaf entry locates just after the vendor directory
entry in its root directory. It is not the layout in the documentation
since the usual descriptor leaf entry locates just after the vendor
immediate entry. Current implementation of firewire-core fail to pick up
the content of descriptor leaf for vendor name. 

This series of changes is to optimize for the quirk, including a slight
correction of documentation for the relevant kernel API. The changes
are written to be accepted to the release candidates of v6.8 so that
they don't conflict to the changes in for-next branch[3], thus they
do not necessarily have a good look.

[1] https://lore.kernel.org/lkml/20240126011705.GA22564@workstation.local/
[2] Configuration ROM for AV/C Devices 1.0 (1394 Trading Association, Dec
2000, TA Document 1999027)
https://web.archive.org/web/20210216003030/http://1394ta.org/wp-content/uploads/2015/07/1999027.pdf
[3] https://git.kernel.org/pub/scm/linux/kernel/git/ieee1394/linux1394.git/log/?h=for-next

Takashi Sakamoto (2):
  firewire: core: correct documentation of fw_csr_string() kernel API
  firewire: core: search descriptor leaf just after vendor directory
    entry in root directory

 drivers/firewire/core-device.c | 18 +++++++++++++-----
 1 file changed, 13 insertions(+), 5 deletions(-)

-- 
2.40.1

Re: [PATCH] firewire: core: send bus reset promptly on gap count error

[Adam G. <ad...@po...>]

Hi,

On Sat, Jan 27, 2024 at 05:37:30PM +0900, Takashi Sakamoto wrote:
> On Tue, Jan 23, 2024 at 12:11:40AM -0800, Adam Goldman wrote:
> > If we are bus manager and the bus has inconsistent gap counts, send a 
> > bus reset immediately instead of trying to read the root node's config 
> > ROM first. Otherwise, we could spend a lot of time trying to read the 
> > config ROM but never succeeding.
> > 
> > This eliminates a 50+ second delay before the FireWire bus is usable 
> > after a newly connected device is powered on in certain circumstances.
> 
> At first, would I request you to explain about the certain
> circumstances in the patch comment? It is really helpful to understand
> the change itself.

The delay occurs if a gap count inconsistency occurs, we are not the 
root node, and we become bus manager. One scenario that causes this is 
with a TI XIO2213B OHCI, the first time a Sony DSR-25 is powered on 
after being connected to the FireWire cable.

> > Link: https://sourceforge.net/p/linux1394/mailman/message/58727806/

This link has a longer description and kernel logs.


> > --- linux-source-6.1.orig/drivers/firewire/core-card.c	2023-09-23 02:11:13.000000000 -0700
> > +++ linux-source-6.1/drivers/firewire/core-card.c	2024-01-22 04:23:06.000000000 -0800
> > @@ -435,6 +435,16 @@
> >  		 * config rom.  In either case, pick another root.
> >  		 */
> >  		new_root_id = local_id;
> > +	} else if (card->gap_count == 0) {
> > +		/* 
> > +		 * If self IDs have inconsistent gap counts, do a
> > +		 * bus reset ASAP. The config rom read might never
> > +		 * complete, so don't wait for it. However, still
> > +		 * send a PHY configuration packet prior to the bus
> > +		 * reset, as permitted by IEEE 1394-2008 8.4.5.2.
> > +		 */
> > +		new_root_id = local_id;
> > +		card->bm_retries = 0;
> >  	} else if (!root_device_is_running) {
> >  		/*
> > 		 * If we haven't probed this device yet, bail out now
> 
> Next, after the condition branches, we can see below lines:
> 
> ```
> 	/*
> 	 * Finally, figure out if we should do a reset or not.  If we have
> 	 * done less than 5 resets with the same physical topology and we
> 	 * have either a new root or a new gap count setting, let's do it.
> 	 */
> 
> 	if (card->bm_retries++ < 5 &&
> 	    (card->gap_count != gap_count || new_root_id != root_id))
> 		do_reset = true;
> ```
> 
> When the value of "card->gap_count" is zero, it would hit the condition of
> "card->gap_count != gap_count". I think the transmission of phy config
> packet and scheduling of short bus reset would be done, regardless of the
> change. Would I ask the main intention to the additional branch?

Without the additional branch, the !root_device_is_running branch will 
be taken (because the root node's config ROM hasn't been read yet), and 
bm_work will go to sleep. Eventually we will give up trying to read the 
config ROM, the root_device==NULL branch will be taken, and the bus 
reset will be done. The additional branch eliminates waiting for the 
config ROM read when gap_count is zero.

Here is the full sequence of events:

1. Bus reset occurs due to newly active device.

2. Self identification process completes. We are not root node. Gap 
counts are inconsistent.

3. build_tree() notices the gap count error and sets gap_count to 0:

> 		/*
> 		 * If PHYs report different gap counts, set an invalid count
> 		 * which will force a gap count reconfiguration and a reset.
> 		 */
> 		if (SELF_ID_GAP_COUNT(q) != gap_count)
> 			gap_count = 0;

4. bm_work() starts and makes us bus manager:

> 		rcode = fw_run_transaction(card, TCODE_LOCK_COMPARE_SWAP,
> 				irm_id, generation, SCODE_100,
> 				CSR_REGISTER_BASE + CSR_BUS_MANAGER_ID,
> 				transaction_data, 8);

5. read_config_rom() starts reading the root node's config ROM.

6. bm_work() wants to know if the root node is cycle master capable. If 
the root node is cycle master capable, we will leave it as the root 
node. Otherwise, we will make ourself the root node. To determine if the 
root node is cycle master capable, we must wait until its config ROM has 
been read:

> 	} else if (!root_device_is_running) {
> 		/*
> 		 * If we haven't probed this device yet, bail out now
> 		 * and let's try again once that's done.
> 		 */
> 		spin_unlock_irq(&card->lock);
> 		goto out;

7a. Without the patch: read_config_rom() reads the first few quadlets 
from the config ROM. Due to the gap count inconsistency, eventually one 
of the reads times out. When read_config_rom() fails, fw_device_init() 
calls it again until MAX_RETRIES is reached. This takes 50+ seconds.

8a. bm_work() sees that we have given up trying to read the config ROM. 
It makes us the root node and does a bus reset:

> 	if (root_device == NULL) {
> 		/*
> 		 * Either link_on is false, or we failed to read the
> 		 * config rom.  In either case, pick another root.
> 		 */
> 		new_root_id = local_id;
> ...
> 	if (card->bm_retries++ < 5 &&
> 	    (card->gap_count != gap_count || new_root_id != root_id))
> 		do_reset = true;

7b. With the patch: Because of the gap count inconsistency, bm_work() 
does not wait for the config ROM to be read. It makes us the root node 
and does a bus reset immediately:

> 	} else if (card->gap_count == 0) {
> 		/*
> 		 * If self IDs have inconsistent gap counts, do a
> 		 * bus reset ASAP. The config rom read might never
> 		 * complete, so don't wait for it. However, still
> 		 * send a PHY configuration packet prior to the
> 		 * bus reset, as permitted by 1394-2008 8.4.5.2.
> 		 */
> 		new_root_id = local_id;
> 		card->bm_retries = 0;
> ...
> 	if (card->bm_retries++ < 5 &&
> 	    (card->gap_count != gap_count || new_root_id != root_id))
> 		do_reset = true;

-- Adam

Re: [PATCH] firewire: core: send bus reset promptly on gap count error

[Takashi S. <o-t...@sa...>]

Hi,

Thanks for the patch. I would like to check some points about the
change.

On Tue, Jan 23, 2024 at 12:11:40AM -0800, Adam Goldman wrote:
> If we are bus manager and the bus has inconsistent gap counts, send a 
> bus reset immediately instead of trying to read the root node's config 
> ROM first. Otherwise, we could spend a lot of time trying to read the 
> config ROM but never succeeding.
> 
> This eliminates a 50+ second delay before the FireWire bus is usable 
> after a newly connected device is powered on in certain circumstances.

At first, would I request you to explain about the certain
circumstances in the patch comment? It is really helpful to understand
the change itself.

> Signed-off-by: Adam Goldman <ad...@po...>
> Link: https://sourceforge.net/p/linux1394/mailman/message/58727806/
> ---
> 
> --- linux-source-6.1.orig/drivers/firewire/core-card.c	2023-09-23 02:11:13.000000000 -0700
> +++ linux-source-6.1/drivers/firewire/core-card.c	2024-01-22 04:23:06.000000000 -0800
> @@ -435,6 +435,16 @@
>  		 * config rom.  In either case, pick another root.
>  		 */
>  		new_root_id = local_id;
> +	} else if (card->gap_count == 0) {
> +		/* 
> +		 * If self IDs have inconsistent gap counts, do a
> +		 * bus reset ASAP. The config rom read might never
> +		 * complete, so don't wait for it. However, still
> +		 * send a PHY configuration packet prior to the bus
> +		 * reset, as permitted by IEEE 1394-2008 8.4.5.2.
> +		 */
> +		new_root_id = local_id;
> +		card->bm_retries = 0;
>  	} else if (!root_device_is_running) {
>  		/*
> 		 * If we haven't probed this device yet, bail out now

Next, after the condition branches, we can see below lines:

```
	/*
	 * Finally, figure out if we should do a reset or not.  If we have
	 * done less than 5 resets with the same physical topology and we
	 * have either a new root or a new gap count setting, let's do it.
	 */

	if (card->bm_retries++ < 5 &&
	    (card->gap_count != gap_count || new_root_id != root_id))
		do_reset = true;
```

When the value of "card->gap_count" is zero, it would hit the condition of
"card->gap_count != gap_count". I think the transmission of phy config
packet and scheduling of short bus reset would be done, regardless of the
change. Would I ask the main intention to the additional branch?


Thanks

Takashi Sakamoto

Re: [PATCH] firewire: core: mask previous entry's type bits when looking for leaf

[Adam G. <ad...@po...>]

On Fri, Jan 26, 2024 at 09:19:17PM +0900, Takashi Sakamoto wrote:
> I think we can handle the quirk of configuration ROM without changing
> the kernel API. Would you test the following patch? (not tested in my
> side).
> 
> ======== 8< --------
> 
> >From 83bf1e04d308ea89c76c64e3168b9701f9d9191b Mon Sep 17 00:00:00 2001
> From: Takashi Sakamoto <o-t...@sa...>
> Date: Fri, 26 Jan 2024 20:37:21 +0900
> Subject: [PATCH] firewire: search descriptor leaf just after vendor directory
>  entry in root directory

Hi Takashi,

I tested your patch with the DVMC-DA1. I also tested it with another 
device with normal placement of the leaf entry. In both cases, it works.

-- Adam

Re: [PATCH] firewire: core: mask previous entry's type bits when looking for leaf

[Takashi S. <o-t...@sa...>]

Hi,

On Fri, Jan 26, 2024 at 12:49:35AM -0800, Adam Goldman wrote:
> On Fri, Jan 26, 2024 at 10:17:05AM +0900, Takashi Sakamoto wrote:
> > Would I request you to update the API documentation of fw_csr_string()
> > as well and send the renewed patch as take 2?
> > 
> > 
> > I have a mixed feeling about the change, but I'll finally accept it since
> > we face the exception against documentation.
> > 
> > As you know, in Annex A of document for configuration ROM of AV/C
> > device[1], we can see the legacy layout of configuration ROM (page 22).
> > In the layout, the descriptor leaf entry for vendor name locates after
> > the immediate value entry for vendor ID, then the directory entry for
> > vendor directory locates. However, in the case of Sony DVMC-DA1, the
> > descriptor leaf entry locates after the directory entry. It is an
> > exception.
> 
> Hi Takashi,
> 
> Thank you for your review and feedback.
> 
> After checking the 1394TA Configuration ROM document again, I agree that 
> the leaf entry for vendor name should be after an immediate value entry 
> according to this standard. The DVMC-DA1 does not conform. We should 
> consider its configuration ROM format to be another variation of the 
> legacy format. This variation is not mentioned in Annex A.
> 
> I will update the API documentation of fw_csr_string() and send a 
> revised patch.

I think we can handle the quirk of configuration ROM without changing
the kernel API. Would you test the following patch? (not tested in my
side).

======== 8< --------

>From 83bf1e04d308ea89c76c64e3168b9701f9d9191b Mon Sep 17 00:00:00 2001
From: Takashi Sakamoto <o-t...@sa...>
Date: Fri, 26 Jan 2024 20:37:21 +0900
Subject: [PATCH] firewire: search descriptor leaf just after vendor directory
 entry in root directory

It appears that Sony DVMC-DA1 has a quirk that the descriptor leaf entry
locates just after the vendor directory entry in root directory. This is
not equivalent to the legacy layout of configuration ROM described in
Configuration ROM for AV/C Devices 1.0 (1394 Trading Association, Dec 2000,
TA Document 1999027).

This commit changes current implementation to parse configuration ROM for
device attributes so that the descriptor leaf entry can be detected for
the vendor name.

$ config-rom-pretty-printer < Sony-DVMC-DA1.img
               ROM header and bus information block
               -----------------------------------------------------------------
1024  041ee7fb  bus_info_length 4, crc_length 30, crc 59387
1028  31333934  bus_name "1394"
1032  e0644000  irmc 1, cmc 1, isc 1, bmc 0, cyc_clk_acc 100, max_rec 4 (32)
1036  08004603  company_id 080046     |
1040  0014193c  device_id 12886219068  | EUI-64 576537731003586876

               root directory
               -----------------------------------------------------------------
1044  0006b681  directory_length 6, crc 46721
1048  03080046  vendor
1052  0c0083c0  node capabilities: per IEEE 1394
1056  8d00000a  --> eui-64 leaf at 1096
1060  d1000003  --> unit directory at 1072
1064  c3000005  --> vendor directory at 1084
1068  8100000a  --> descriptor leaf at 1108

               unit directory at 1072
               -----------------------------------------------------------------
1072  0002cdbf  directory_length 2, crc 52671
1076  1200a02d  specifier id
1080  13010000  version

               vendor directory at 1084
               -----------------------------------------------------------------
1084  00020cfe  directory_length 2, crc 3326
1088  17fa0000  model
1092  81000008  --> descriptor leaf at 1124

               eui-64 leaf at 1096
               -----------------------------------------------------------------
1096  0002c66e  leaf_length 2, crc 50798
1100  08004603  company_id 080046     |
1104  0014193c  device_id 12886219068  | EUI-64 576537731003586876

               descriptor leaf at 1108
               -----------------------------------------------------------------
1108  00039e26  leaf_length 3, crc 40486
1112  00000000  textual descriptor
1116  00000000  minimal ASCII
1120  536f6e79  "Sony"

               descriptor leaf at 1124
               -----------------------------------------------------------------
1124  0005001d  leaf_length 5, crc 29
1128  00000000  textual descriptor
1132  00000000  minimal ASCII
1136  44564d43  "DVMC"
1140  2d444131  "-DA1"
1144  00000000

Signed-off-by: Takashi Sakamoto <o-t...@sa...>
---
 drivers/firewire/core-device.c | 10 +++++++++-
 1 file changed, 9 insertions(+), 1 deletion(-)

diff --git a/drivers/firewire/core-device.c b/drivers/firewire/core-device.c
index 0547253d16fe..30a734ee9de9 100644
--- a/drivers/firewire/core-device.c
+++ b/drivers/firewire/core-device.c
@@ -368,8 +368,16 @@ static ssize_t show_text_leaf(struct device *dev,
 	for (i = 0; i < ARRAY_SIZE(directories) && !!directories[i]; ++i) {
 		int result = fw_csr_string(directories[i], attr->key, buf, bufsize);
 		// Detected.
-		if (result >= 0)
+		if (result >= 0) {
 			ret = result;
+		} else if (i == 0 && attr->key == CSR_VENDOR) {
+			// Sony DVMC-DA1 has configuration ROM such that the descriptor leaf entry
+			// in the root directory follows to the directory entry for vendor ID
+			// instead of the immediate value for vendor ID.
+			result = fw_csr_string(directories[i], CSR_DIRECTORY | attr->key, buf, bufsize);
+			if (result >= 0)
+				ret = result;
+		}
 	}
 
 	if (ret >= 0) {
-- 
2.40.1

======== 8< --------


Regards

Takashi Sakamoto

Re: [PATCH] firewire: core: mask previous entry's type bits when looking for leaf

[Adam G. <ad...@po...>]

On Fri, Jan 26, 2024 at 10:17:05AM +0900, Takashi Sakamoto wrote:
> Would I request you to update the API documentation of fw_csr_string()
> as well and send the renewed patch as take 2?
> 
> 
> I have a mixed feeling about the change, but I'll finally accept it since
> we face the exception against documentation.
> 
> As you know, in Annex A of document for configuration ROM of AV/C
> device[1], we can see the legacy layout of configuration ROM (page 22).
> In the layout, the descriptor leaf entry for vendor name locates after
> the immediate value entry for vendor ID, then the directory entry for
> vendor directory locates. However, in the case of Sony DVMC-DA1, the
> descriptor leaf entry locates after the directory entry. It is an
> exception.

Hi Takashi,

Thank you for your review and feedback.

After checking the 1394TA Configuration ROM document again, I agree that 
the leaf entry for vendor name should be after an immediate value entry 
according to this standard. The DVMC-DA1 does not conform. We should 
consider its configuration ROM format to be another variation of the 
legacy format. This variation is not mentioned in Annex A.

I will update the API documentation of fw_csr_string() and send a 
revised patch.

-- Adam

Re: [PATCH] firewire: core: mask previous entry's type bits when looking for leaf

[Takashi S. <o-t...@sa...>]

Hi,

On Thu, Jan 25, 2024 at 04:15:12AM -0800, Adam Goldman wrote:
> When searching a configuration ROM directory for a leaf corresponding to 
> a specific key_ID, disregard the type bits of the directory entry.
> 
> The configuration ROM of FireWire devices can contain textual descriptor 
> leafs (strings) for vendor name and model name. We use these to populate 
> the vendor_name and model_name entries in sysfs. Each descriptor leaf has a 
> descriptor directory entry pointing to it. The identity of the descriptor 
> leaf is indicated by the key_ID of the directory entry immediately before 
> the descriptor leaf's directory entry. The key_ID is the low 6 bits of the 
> high byte of the directory entry, and the type is the high 2 bits.
> 
> In most cases, the directory entry before a descriptor directory entry will 
> be an immediate value (type=0). However, it is also valid for it to be a 
> directory (type=3). Thus, when looking for a specific leaf, we must mask 
> off the type bits and compare only the key_ID.
> 
> One affected device is the Sony DVMC-DA1, which is missing the vendor_name 
> sysfs entry without this change.
> 
> The recent commit 141d9c6e003b806d8faeddeec7053ee2691ea61a fixed missing 
> model and model_name entries for the DVMC-DA1, but those were caused by a 
> different issue.
> 
> Signed-Off-By: Adam Goldman <ad...@po...>
> ---
> 
> --- linux-6.8-rc1.orig/drivers/firewire/core-device.c	2024-01-21 14:11:32.000000000 -0800
> +++ linux-6.8-rc1/drivers/firewire/core-device.c	2024-01-24 03:56:56.000000000 -0800
> @@ -72,7 +72,7 @@
>  
>  	fw_csr_iterator_init(&ci, directory);
>  	while (fw_csr_iterator_next(&ci, &key, &value)) {
> -		if (last_key == search_key &&
> +		if ((last_key & 0x3f) == search_key &&
>  		    key == (CSR_DESCRIPTOR | CSR_LEAF))
>  			return ci.p - 1 + value;

Would I request you to update the API documentation of fw_csr_string()
as well and send the renewed patch as take 2?


I have a mixed feeling about the change, but I'll finally accept it since
we face the exception against documentation.

As you know, in Annex A of document for configuration ROM of AV/C
device[1], we can see the legacy layout of configuration ROM (page 22).
In the layout, the descriptor leaf entry for vendor name locates after
the immediate value entry for vendor ID, then the directory entry for
vendor directory locates. However, in the case of Sony DVMC-DA1, the
descriptor leaf entry locates after the directory entry. It is an
exception.

The change brings the behaviour change of fw_csr_string() since it is
currently coded to pick up the text pointed by the descriptor leaf entry
just after the immediate value entry. Fortunately, as long as I know, the
change is safe and brings no regression.

In the concept of software stack in kernel, whether the string is picked
up or not is not so important, since it is just for human readability.
It is just enough to pick up information to detect the relationship
between node and unit and their corresponding drivers. The parse of
configuration ROM should be done in userspace application again.
Actually the most of userspace applications are programmed so.

In the case of systemd udev/hwdb, it is not so preferable to put
device-dependent code, therefore the device attributes are important in
our case. But the vendor string provided by the stack is not necessarily
useful since hwdb can fulfill it now[2].

... But the above are just theories. The world has many complicated
things, I know. So I accept your proposal. But note that the preferable
way is to find the other devices which have the configuration ROM similar
to the case. We have already implemented the support for the legacy layout
of configuration ROM. It's time for you to start collecting the
configuration ROMs for digital video devices, like I did for audio and
music units in IEEE 1394 bus[3][4].

[1] Configuration ROM for AV/C Devices 1.0 (1394 Trading Association, Dec 2000,
TA Document 1999027)
https://web.archive.org/web/20210216003030/http://1394ta.org/wp-content/uploads/2015/07/1999027.pdf
[2] https://github.com/systemd/systemd/pull/31054
[3] https://github.com/takaswie/am-config-roms/
[4] https://github.com/systemd/systemd/blob/main/hwdb.d/80-ieee1394-unit-function.hwdb


Thanks

Takashi Sakamoto

[PATCH] firewire: core: mask previous entry's type bits when looking for leaf

[Adam G. <ad...@po...>]

When searching a configuration ROM directory for a leaf corresponding to 
a specific key_ID, disregard the type bits of the directory entry.

The configuration ROM of FireWire devices can contain textual descriptor 
leafs (strings) for vendor name and model name. We use these to populate 
the vendor_name and model_name entries in sysfs. Each descriptor leaf has a 
descriptor directory entry pointing to it. The identity of the descriptor 
leaf is indicated by the key_ID of the directory entry immediately before 
the descriptor leaf's directory entry. The key_ID is the low 6 bits of the 
high byte of the directory entry, and the type is the high 2 bits.

In most cases, the directory entry before a descriptor directory entry will 
be an immediate value (type=0). However, it is also valid for it to be a 
directory (type=3). Thus, when looking for a specific leaf, we must mask 
off the type bits and compare only the key_ID.

One affected device is the Sony DVMC-DA1, which is missing the vendor_name 
sysfs entry without this change.

The recent commit 141d9c6e003b806d8faeddeec7053ee2691ea61a fixed missing 
model and model_name entries for the DVMC-DA1, but those were caused by a 
different issue.

Signed-Off-By: Adam Goldman <ad...@po...>
---

--- linux-6.8-rc1.orig/drivers/firewire/core-device.c	2024-01-21 14:11:32.000000000 -0800
+++ linux-6.8-rc1/drivers/firewire/core-device.c	2024-01-24 03:56:56.000000000 -0800
@@ -72,7 +72,7 @@
 
 	fw_csr_iterator_init(&ci, directory);
 	while (fw_csr_iterator_next(&ci, &key, &value)) {
-		if (last_key == search_key &&
+		if ((last_key & 0x3f) == search_key &&
 		    key == (CSR_DESCRIPTOR | CSR_LEAF))
 			return ci.p - 1 + value;
 

[PATCH] firewire: core: send bus reset promptly on gap count error

[Adam G. <ad...@po...>]

If we are bus manager and the bus has inconsistent gap counts, send a 
bus reset immediately instead of trying to read the root node's config 
ROM first. Otherwise, we could spend a lot of time trying to read the 
config ROM but never succeeding.

This eliminates a 50+ second delay before the FireWire bus is usable 
after a newly connected device is powered on in certain circumstances.

Signed-off-by: Adam Goldman <ad...@po...>
Link: https://sourceforge.net/p/linux1394/mailman/message/58727806/
---

--- linux-source-6.1.orig/drivers/firewire/core-card.c	2023-09-23 02:11:13.000000000 -0700
+++ linux-source-6.1/drivers/firewire/core-card.c	2024-01-22 04:23:06.000000000 -0800
@@ -435,6 +435,16 @@
 		 * config rom.  In either case, pick another root.
 		 */
 		new_root_id = local_id;
+	} else if (card->gap_count == 0) {
+		/* 
+		 * If self IDs have inconsistent gap counts, do a
+		 * bus reset ASAP. The config rom read might never
+		 * complete, so don't wait for it. However, still
+		 * send a PHY configuration packet prior to the bus
+		 * reset, as permitted by IEEE 1394-2008 8.4.5.2.
+		 */
+		new_root_id = local_id;
+		card->bm_retries = 0;
 	} else if (!root_device_is_running) {
 		/*
		 * If we haven't probed this device yet, bail out now

Re: Question regarding linux1394 and bug report

[Adam G. <ad...@po...>]

Hi Tasos,

On Sun, Jan 21, 2024 at 08:05:48PM +0200, Tasos Sahanidis wrote:
> The following is from 2.6.35-rc3 on Ubuntu 10.10:
...
> [  530.690859] firewire_ohci: IRQ 00000080 IR

OK, that's the video transmission that was missing from the previous 
message.

> This is a typical failed capture attempt on newer kernels (6.7):
> $ dvgrab -noavc -guid 00808801035809f1 -d 1
> libiec61883 warning: Transmission node has no plugs online!
...
> [ 3313.955351] firewire_ohci 0000:01:03.0: AT spd 0 tl 35, ffc1 -> ffc0, ack_pending , QR req, fffff0000904
> [ 3313.956255] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
> [ 3313.956261] firewire_ohci 0000:01:03.0: AR spd 0 tl 35, ffc0 -> ffc1, ack_complete, QR resp = 003f007a

The camera's oPCR0 register (the response to the read of '904) has the 
online and broadcast bits clear, indicating that the output plug will 
not be sending any video. I wonder why? (Compare to the value c03f3c7a 
in the 2.6.35-rc3 case, which has the online and broadcast bits set.)

What do the 6.7 logs look like when the camera is first turned on, 
starting with the first evt_bus_reset?

> At the moment I suspect there might be a race somewhere.

I agree, it must be timing related. That explains why it was affected by 
the seemingly unrelated workqueue change.

-- Adam

Gap count inconsistency causes long delay

[Adam G. <ad...@po...>]

Hi,

The first time a Sony DSR-25 is powered on after it is connected to a 
Linux PC with a TI XIO2213B based FireWire card, sometimes it takes more 
than 50 seconds before the FireWire bus is usable. A gap count 
inconsistency occurs and the bus manager is supposed to generate a bus 
reset. However, Linux tries to read the root node's configuration ROM 
before generating a bus reset. The configuration ROM can't be read due 
to the gap count inconsistency. Eventually, Linux gives up trying to 
read the configuration ROM, and then it generates a bus reset which 
resolves the gap count inconsistency.

By skipping the configuration ROM read when there is a gap count 
inconsistency, the 50+ second delay can be eliminated. I will send a 
patch for this today.

Conditions to reproduce this problem:

Tested with a Sony DSR-25 and a SY-PEX30016 PCI Express OHCI card with 
the TI XIO2213B chip.

1. The problem will occur if the device is connected directly to the 
computer. It will also occur if the device is connected through a 
FireWire 800 repeater with a TI chip (tested with PCC-70929 repeater 
cable). It can't be reproduced if the device is connected through a 
FireWire 400 hub.

2. With the DSR-25 powered off, unplug the FireWire cable from the 
DSR-25 and plug it back in.

3. Turn on the DSR-25. A gap count inconsistency will occur the first 
time the DSR-25 is turned on after plugging in the cable. If the DSR-25 
is power cycled again without unplugging the cable, the problem will not 
recur.

Here is a kernel log excerpt. I trimmed it for size.

> [ 8458.584473] IRQ 00000010 AR_req
> [ 8458.585918] IRQ 00810000 selfID cycleInconsistent
> [ 8458.587237] isochronous cycle inconsistent
> [ 8458.588622] AR evt_bus_reset, generation 2
> [ 8458.589975] AR evt_bus_reset, generation 2
> [ 8458.591340] ignoring spurious self IDs
> [ 8458.592707] 2 selfIDs, generation 3, local node ID ffc0
> [ 8458.594086] selfID 0: 807fcc58, phy 0 [--p] beta gc=63 -3W Lc
> [ 8458.595468] selfID 0: 816c08c2, phy 1 [c..] S100 gc=44 +0W Lci

The DSR-25 was powered on. It generated a bus reset. The self-identify 
process was completed. The Linux PC has node ID ffc0, and the DSR-25 has 
node ID ffc1. (The DSR-25's self-ID packet can be recognized because it 
is S100 speed.) The DSR-25 is root node and IRM. The PC has a gap count 
value of 63 and the DSR-25 has a gap count value of 44. This gap count 
inconsistency is called a "Gap Count Error" event in the IEEE 1394 
standard. The cause of the gap count inconsistency will be described 
later. When nodes on a FireWire bus have different gap count values, 
communication will be unreliable. IEEE 1394a-2000 and 1394-2008 require 
the bus manager to correct a gap count error by initiating a bus reset.

> [ 8458.728492] AT spd 0 tl 1c, ffc0 -> ffc1, ack_pending , Lk req, fffff000021c 8,2
> [ 8458.729968] AR spd 0 tl 1c, ffc1 -> ffc0, ack_complete, Lk resp 4,2

The Linux PC attempted to become the bus manager. It succeeded. Now the 
Linux PC is bus manager. The DSR-25 is still the root node and IRM.

> [ 8459.100669] AT spd 0 tl 1d, ffc0 -> ffc1, ack_pending , QR req, fffff0000400
> [ 8459.102255] AR spd 0 tl 1d, ffc1 -> ffc0, ack_complete, QR resp = 04042592
> [ 8459.103880] firewire_core 0000:02:00.0: rediscovered device fw0
> [ 8459.105537] IRQ 00000021 AR_resp AT_req
> [ 8459.107171] AR spd 0 tl 35, ffc1 -> ffc0, ack_complete, QR resp = 31333934
> [ 8459.108804] AT spd 0 tl 35, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000404

The Linux PC has started reading the DSR-25's configuration ROM.

> ...
> [ 8459.204224] AT spd 0 tl 03, ffc0 -> ffc1, ack_pending , QR req, fffff000043c
> [ 8459.206068] IRQ 00000020 AR_resp
> [ 8459.207968] AR spd 0 tl 03, ffc1 -> ffc0, ack_complete, QR resp = 1720000f
> [ 8459.209918] IRQ 00000001 AT_req
> [ 8459.211865] AT spd 0 tl 04, ffc0 -> ffc1, ack_pending , QR req, fffff0000440
> [ 8464.281568] IRQ 00000001 AT_req
> [ 8464.283981] IRQ 00000020 AR_resp
> [ 8464.286279] AT spd 0 tl 05, ffc0 -> ffc1, ack_pending , QR req, fffff0000400
> [ 8464.288562] AR spd 0 tl 05, ffc1 -> ffc0, ack_complete, QR resp = 04042592

We were able to read 400-43c from the config ROM, but reading 440 failed 
due to the gap count inconsistency. After 5 seconds, the read attempt 
timed out. We started another attempt to read the config ROM, starting 
from the beginning at 400.

> ...
> [ 8464.340941] AT spd 0 tl 0c, ffc0 -> ffc1, ack_pending , QR req, fffff000041c
> [ 8464.342942] AR spd 0 tl 0c, ffc1 -> ffc0, ack_complete, QR resp = 8100000a
> [ 8464.345010] IRQ 00000001 AT_req
> [ 8464.347133] AT spd 0 tl 0d, ffc0 -> ffc1, ack_pending , QR req, fffff0000420
> [ 8469.401635] IRQ 00000001 AT_req
> [ 8469.404249] IRQ 00000020 AR_resp
> [ 8469.406740] AT spd 0 tl 0e, ffc0 -> ffc1, ack_pending , QR req, fffff0000400
> [ 8469.409216] AR spd 0 tl 0e, ffc1 -> ffc0, ack_complete, QR resp = 04042592

This time, we were only able to read 400-41c. Reading 420 failed. After 
5 seconds, the read attempt timed out, and we started over at 400 again.

> ...
> [ 8510.986710] AT spd 0 tl 3a, ffc0 -> ffc1, ack_pending , QR req, fffff0000438
> [ 8510.991578] IRQ 00000020 AR_resp
> [ 8510.993368] AR spd 0 tl 3a, ffc1 -> ffc0, ack_complete, QR resp = 13010001
> [ 8510.995134] IRQ 00000001 AT_req
> [ 8510.996927] AT spd 0 tl 3b, ffc0 -> ffc1, ack_pending , QR req, fffff000043c
> [ 8513.018141] firewire_core 0000:02:00.0: giving up on node ffc1: reading config rom failed: timeout

We made a total of 10 attempts to read the config ROM. Each attempt took 
slightly more than 5 seconds. After the tenth attempt, we give up.

> [ 8513.020594] firewire_core 0000:02:00.0: phy config: new root=ffc0, gap_count=5
> [ 8513.022978] IRQ 00000001 AT_req
> [ 8513.025306] AT ack_complete, PHY 00c50000 ff3affff
> [ 8513.027664] IRQ 00000010 AR_req
> [ 8513.030028] IRQ 00010000 selfID
> [ 8513.032270] AR evt_bus_reset, generation 4
> [ 8513.034463] AR evt_bus_reset, generation 4
> [ 8513.036614] 2 selfIDs, generation 5, local node ID ffc1
> [ 8513.038729] selfID 0: 80450880, phy 0 [p..] S100 gc=5 +0W Lc
> [ 8513.040842] selfID 0: 8145cc5e, phy 1 [--c] beta gc=5 -3W Lci

After giving up on the config ROM read, we finally send a PHY 
configuration packet and a bus reset. This time, both nodes have a gap 
count of 5. The DSR-25 has a node ID of ffc0, and the Linux PC has a 
node ID of ffc1. The Linux PC is the root node and IRM.

> [ 8513.562176] IRQ 00000021 AR_resp AT_req
> [ 8513.564389] AR spd 0 tl 3d, ffc0 -> ffc1, ack_complete, QR resp = 04042592
> [ 8513.566489] AT spd 0 tl 3d, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400
> ...
> [ 8513.803443] AT spd 0 tl 36, ffc1 -> ffc0, ack_pending , QR req, fffff0000450
> [ 8513.805051] AR spd 0 tl 36, ffc0 -> ffc1, ack_complete, QR resp = 536f6e79
> [ 8513.806916] firewire_core 0000:02:00.0: created device fw1: GUID 08004601025e582a, S100

After the bus reset, the config ROM could be succesfully read. The Linux 
PC recognized the DSR-25. In total, this took 55 seconds!

Because communication is unreliable when the gap count is inconsistent, 
the bus manager should send a bus reset as soon as possible. I modified 
bm_work() to do that. Here is a trimmed kernel log after the change:

> [13093.728598] AR evt_bus_reset, generation 2
> [13093.730467] IRQ 00810000 selfID cycleInconsistent
> [13093.730478] isochronous cycle inconsistent
> [13093.734034] AR evt_bus_reset, generation 2
> [13093.735812] ignoring spurious self IDs
> [13093.737558] 2 selfIDs, generation 3, local node ID ffc0
> [13093.739282] selfID 0: 807fcc58, phy 0 [--p] beta gc=63 -3W Lc
> [13093.741019] selfID 0: 816c08c2, phy 1 [c..] S100 gc=44 +0W Lci

The DSR-25 was powered on. Again, there was a gap count inconsistency.

> [13093.874924] AT spd 0 tl 1c, ffc0 -> ffc1, ack_pending , Lk req, fffff000021c 8,2
> [13093.876624] AR spd 0 tl 1c, ffc1 -> ffc0, ack_complete, Lk resp 4,2

The Linux PC became bus master.

> [13093.878319] firewire_core 0000:02:00.0: phy config: new root=ffc0, gap_count=5
> [13093.880082] IRQ 00000001 AT_req
> [13093.881780] AT ack_complete, PHY 00c50000 ff3affff
> [13093.883461] IRQ 00000010 AR_req
> [13093.885061] AR evt_bus_reset, generation 4
> [13093.886695] IRQ 00010000 selfID
> [13093.888261] AR evt_bus_reset, generation 4
> [13093.889828] 2 selfIDs, generation 5, local node ID ffc1
> [13093.891356] selfID 0: 80450880, phy 0 [p..] S100 gc=5 +0W Lc
> [13093.892900] selfID 0: 8145cc5e, phy 1 [--c] beta gc=5 -3W Lci

After becoming bus master, we sent a PHY configuration packet and bus 
reset immediately. The gap count inconsistency has been corrected.

> [13094.401037] AR spd 0 tl 20, ffc0 -> ffc1, ack_complete, QR resp = 04042592
> [13094.402517] AT spd 0 tl 20, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000400
> ...
> [13094.641750] AT spd 0 tl 19, ffc1 -> ffc0, ack_pending , QR req, fffff0000450
> [13094.643764] IRQ 00000020 AR_resp
> [13094.645718] AR spd 0 tl 19, ffc0 -> ffc1, ack_complete, QR resp = 536f6e79
> [13094.647972] firewire_core 0000:02:00.0: created device fw1: GUID 08004601025e582a, S100

We read the config ROM successfully and recognized the DSR-25. The total 
time was about 1 second.

Another way to deal with a gap count inconsistency would be to delay 
becoming bus master, and give the IRM a chance to reset the bus. 
However, the original IEEE 1394-1995 does not explicitly say how a bus 
manager should react to a gap count error. So, an IRM that is not IEEE 
1394a compliant might never correct the gap count error. For that 
reason, I think it's better that we should become bus master and reset 
the bus.

I considered that if the gap count is inconsistent, a PHY configuration 
packet might not be successful, so it could be desirable to skip the PHY 
configuration packet before the bus reset in this case. However, IEEE 
1394a-2000 and IEEE 1394-2008 say that the bus manager may transmit a 
PHY configuration packet before a bus reset when correcting a gap count 
error. Since the standard endorses this, I decided it's safe to retain 
the PHY configuration packet transmission.

Normally, after a topology change, we will reset the bus a maximum of 5 
times to change the root node and perform gap count optimization. 
However, if there is a gap count inconsistency, we must always generate 
a bus reset. Otherwise the gap count inconsistency will persist and 
communication will be unreliable. For that reason, if there is a gap 
count inconstency, I generate a bus reset even if we already reached the 
5 reset limit.

To understand why the DSR-25 set its gap count to 44, we can look at a 
FireWire bus analyzer trace. I used a Data Transit bus analyzer 
connected to the DSR-25. The Linux PC was not connected for the 
following trace.

> 005 BUS RESET                                                  298.1 MS 
> 006 SELFID PKT0  807F0882  01 ID=00 L=1 GAP=3F SP=100 C=1 I=1  168.7 US 
> 007 SELFID PKT0  7F80F77D  02 PWR=0 P0=PRNT P1=N/P  P2=N/P     0.330 US 
> 008 NODEID RCVD        01     ANALYZER NODE_ID=01              0.750 US 

After the first reset, the DSR-25 started with a gap count of 63, as 
required by the IEEE 1394 standard. The DSR-25 is the IRM, and the bus 
analyzer is the root node.

> 009 SUBACTN GAP                                                11.54 US 
> 010 PHY_CONFIG   00EC0000  01 ROOT ID=00  R=1  T=1  GAP=2C     640.9 MS 
> 011 ASYNC        FF13FFFF  02                                  0.330 US 
> 012 SUBACTN GAP                                                7.710 US 
> 013 BUS RESET                                                  6.465 MS 

According to IEEE 1394, after the self identification process, the IRM 
should wait >=625ms for a bus manager to update the BUS_MANAGER_ID 
register. If this does not happen, there is no bus manager present and 
the IRM is permitted to perform gap count optimization. In this case, 
the DSR-25 waited ~640ms and then set the gap count to 44. This value 
gives better performance than the default value of 63, but is safe with 
an assumed maximum hop count of 16. The DSR-25 does not try to determine 
the actual hop count or round-trip delay.

> 014 NODEID RCVD        00     ANALYZER NODE_ID=00              167.6 US 
> 015 SELFID PKT0  816C08C2  01 ID=01 L=1 GAP=2C SP=100 C=1 I=1  2.280 US 
> 016 SELFID PKT0  7E93F73D  02 PWR=0 P0=CHLD P1=N/P  P2=N/P     0.330 US 

After the bus reset, the DSR-25 has a gap count of 44.

Normally, this sequence of events won't happen with a Linux PC 
connected, because the Linux PC will become bus manager. For testing 
purposes, it's possible to prevent Linux from becoming the bus manager 
or IRM by placing "goto out_put_card;" at the top of bm_work() and 
commenting out "| PHY_CONTENDER" in ohci_enable(). Here is the trimmed 
kernel log:

> [17268.355762] AR evt_bus_reset, generation 7
> [17268.357492] IRQ 00810000 selfID cycleInconsistent
> [17268.357503] isochronous cycle inconsistent
> [17268.360835] AR evt_bus_reset, generation 7
> [17268.362514] ignoring spurious self IDs
> [17268.364173] 2 selfIDs, generation 8, local node ID ffc0
> [17268.365857] selfID 0: 807fc458, phy 0 [--p] beta gc=63 -3W L
> [17268.367548] selfID 0: 816c08c2, phy 1 [c..] S100 gc=44 +0W Lci

The first time the DSR-25 is powered on, there is a gap count 
inconsistency.

> ...
> [17274.340890] AT spd 0 tl 13, ffc0 -> ffc1, ack_pending , QR req, fffff0000450
> [17274.342897] IRQ 00000020 AR_resp
> [17274.344863] AR spd 0 tl 13, ffc1 -> ffc0, ack_complete, QR resp = 536f6e79
> [17274.347108] firewire_core 0000:02:00.0: created device fw1: GUID 08004601025e582a, S100

As IRM, the DSR-25 resets the bus and we successfully read the config 
ROM. We don't care about that, so I omitted most of the log.

Next, I power cycled the DSR-25 without unplugging the FireWire cable.

> [17361.569240] AR evt_bus_reset, generation 12
> [17361.571137] IRQ 00810000 selfID cycleInconsistent
> [17361.571148] isochronous cycle inconsistent
> [17361.574786] AR evt_bus_reset, generation 12
> [17361.576593] 2 selfIDs, generation 13, local node ID ffc0
> [17361.578418] selfID 0: 807fc458, phy 0 [--p] beta gc=63 -3W L
> [17361.580209] selfID 0: 817f08c2, phy 1 [c..] S100 gc=63 +0W Lci

This time, both nodes start out with the correct default gap count of 
63!

> [17362.098623] AT spd 0 tl 1a, ffc0 -> ffc1, ack_pending , QR req, fffff0000400
> [17362.100451] IRQ 00000020 AR_resp
> [17362.102279] firewire_core 0000:02:00.0: rediscovered device fw0
> [17362.104026] AR spd 0 tl 1a, ffc1 -> ffc0, ack_complete, QR resp = 04042592
> ...
> [17362.200874] AT spd 0 tl 3f, ffc0 -> ffc1, ack_pending , QR req, fffff0000438
> [17362.202849] IRQ 00000020 AR_resp
> [17362.204784] AR spd 0 tl 3f, ffc1 -> ffc0, ack_complete, QR resp = 13010001
> [17362.208782] AT spd 0 tl 00, ffc0 -> ffc1, ack_pending , QR req, fffff000043c

We begin reading the config ROM.

> [17362.212683] AR ack_complete, PHY 01ec0000 fe13ffff

About 630ms has passed since the self ID completed, but there is no bus 
manager. As IRM, the DSR-25 sends a PHY configuration packet to change 
the gap count to 44.

> [17362.216780] AR evt_bus_reset, generation 14
> [17362.218694] IRQ 00010000 selfID
> [17362.220582] 2 selfIDs, generation 14, local node ID ffc0
> [17362.222480] selfID 0: 806cc458, phy 0 [--p] beta gc=44 -3W L
> [17362.224341] selfID 0: 816c08c2, phy 1 [c..] S100 gc=44 +0W Lci

We received the DSR-25's PHY configuration packet, so when the DSR-25 
generates a bus reset, all nodes have the same gap count, 44.

> [17367.282795] AR spd 0 tl 01, ffc1 -> ffc0, ack_complete, QR resp = 04042592
> [17367.284639] AT spd 0 tl 01, ffc0 -> ffc1, pending/cancelled, QR req, fffff0000400
> ...
> [17367.539968] AT spd 0 tl 21, ffc0 -> ffc1, ack_pending , QR req, fffff0000450
> [17367.541976] IRQ 00000020 AR_resp
> [17367.543942] AR spd 0 tl 21, ffc1 -> ffc0, ack_complete, QR resp = 536f6e79
> [17367.546191] firewire_core 0000:02:00.0: created device fw1: GUID 08004601025e582a, S100

After the bus reset, we restart the config ROM read, and we successfully 
read the config ROM.

The gap count inconsistency only occurs when the DSR-25 is plugged 
directly into the computer. Since the bus analyzer's second FireWire 
port acts as a FireWire 400 hub, it is not possible to reproduce the 
problem when the DSR-25 is chained to the computer through the analyzer. 
However, it can be reproduced when the DSR-25 is connected to one port 
of the computer's FireWire card and the analyzer is connected to another 
port of the FireWire card. In this configuration, the OHCI chip also 
acts as a FireWire 800 hub. Here is the beginning of the bus analyzer 
trace:

> 000 BUS RESET                                                  0.000 USX
> 001 NODEID RCVD        00     ANALYZER NODE_ID=00              250.9 US 
> 002 SELFID PKT0  817FCC9C  01 ID=01 L=1 GAP=3F SP=800 C=1 I=0  2.680 US 
> 003 SELFID PKT0  7E803363  02 PWR=4 P0=PRNT P1=OFF  P2=CHLD    0.330 US 
> 004 SELFID PKT0  826C08C2  01 ID=02 L=1 GAP=2C SP=100 C=1 I=1  1.600 US 
> 005 SELFID PKT0  7D93F73D  02 PWR=0 P0=CHLD P1=N/P  P2=N/P     0.330 US 

The first activity the analyzer sees is a bus reset and then the self 
IDs with inconsistent gap counts. With the FireWire card acting as hub, 
the analyzer never sees a PHY configuration packet from the DSR-25.

It looks like when the XIO2213B chip is initially connected to a 
FireWire device, its PHY enters a state where it will not receive 
packets. After the link has been established for about 1 second, it will 
begin receiving packets. If the DSR-25 sends a PHY configuration packet 
soon after powering on, the XIO2213B's PHY will not hear this packet. It 
will not obey the configuration command, nor will it send the packet to 
the host or to the XIO2213B's other ports. So, the DSR-25's initial 
attempt to perform gap count optimization as IRM will result in 
inconsistent gap count. Once the XIO2213B begins receiving packets on a 
port, this port will remain able to receive packets until the FireWire 
cable is unplugged.

However, I am not completely certain that this is the correct 
explanation. For example, it might be possible that the XIO2213B is OK 
and the DSR-25 is incorrectly trying to send the PHY configuration 
packet before the link is established.

In any case, by changing bm_work() to immediately generate a bus reset 
when the gap count is inconsistent, the gap count error is resolved and 
the FireWire bus will become usable rapidly.

-- Adam

Re: [PATCH 1/2] firewire: Kill unnecessary buf check in device_attribute.show

[Takashi S. <o-t...@sa...>]

Hi,

On Mon, Jan 22, 2024 at 01:39:41PM +0800, Li Zhijian wrote:
> Per Documentation/filesystems/sysfs.rst:
> > sysfs allocates a buffer of size (PAGE_SIZE) and passes it to the
> > method.
> 
> So we can kill the unnecessary buf check safely.
> 
> Signed-off-by: Li Zhijian <liz...@fu...>
> ---
>  drivers/firewire/core-device.c | 14 +++-----------
>  1 file changed, 3 insertions(+), 11 deletions(-)

Applied both patches to linux-next branch, since they are not so-urgent 
fixes.


Thanks

Takashi Sakamoto

Re: Question regarding linux1394 and bug report

[Tasos S. <ta...@ta...>]

On 2024-01-18 02:00, Adam Goldman wrote:
> Hi Tasos,
> 
> Are you sure 2.6.35-rc3 is working? The "fw_working" log doesn't appear 
> to include any video transmission.

Hi Adam,

It is possible I trimmed it to not spam the mailing list. As I do not
remember, I generated fresh logs. It definitely works though as I
used that old kernel to rip a few tapes.

The following is from 2.6.35-rc3 on Ubuntu 10.10:
$ dvgrab -noavc -guid 00808801035809f1 -d 1
libiec61883 error: Failed to get channels available.
Established connection over channel 63
Waiting for DV...
Capture Started
"dvgrab-004.dv":     3.43 MiB 25 frames timecode 00:00:00.00 date 2024.01.18 06:09:43
Capture Stopped

[  494.955666] firewire_ohci: IRQ 00200000 cycle64Seconds
[  530.091424] firewire_ohci: IRQ 00000001 AT_req
[  530.091440] firewire_ohci: AT spd 0 tl 02, ffc1 -> ffc0, ack_pending , QR req, fffff000040c
[  530.092174] firewire_ohci: IRQ 00000020 AR_resp
[  530.092181] firewire_ohci: AR spd 0 tl 02, ffc0 -> ffc1, ack_complete, QR resp = 00808801
[  530.092240] firewire_ohci: IRQ 00000001 AT_req
[  530.092245] firewire_ohci: AT spd 0 tl 03, ffc1 -> ffc0, ack_pending , QR req, fffff0000410
[  530.093153] firewire_ohci: IRQ 00000020 AR_resp
[  530.093158] firewire_ohci: AR spd 0 tl 03, ffc0 -> ffc1, ack_complete, QR resp = 035809f1
[  530.412749] firewire_ohci: IRQ 00000001 AT_req
[  530.412754] firewire_ohci: AT spd 0 tl 04, ffc1 -> ffc0, ack_pending , QR req, fffff0000900
[  530.413935] firewire_ohci: IRQ 00000020 AR_resp
[  530.413940] firewire_ohci: AR spd 0 tl 04, ffc0 -> ffc1, ack_complete, QR resp = 3fffff01
[  530.413960] firewire_ohci: IRQ 00000001 AT_req
[  530.413964] firewire_ohci: AT spd 0 tl 05, ffc1 -> ffc0, ack_pending , QR req, fffff0000904
[  530.414964] firewire_ohci: IRQ 00000020 AR_resp
[  530.414968] firewire_ohci: AR spd 0 tl 05, ffc0 -> ffc1, ack_complete, QR resp = c03f3c7a
[  530.652665] firewire_ohci: IRQ 00000001 AT_req
[  530.652671] firewire_ohci: AT spd 0 tl 06, ffc1 -> ffc0, ack_pending , QR req, fffff0000900
[  530.653797] firewire_ohci: IRQ 00000020 AR_resp
[  530.653802] firewire_ohci: AR spd 0 tl 06, ffc0 -> ffc1, ack_complete, QR resp = 3fffff01
[  530.655259] firewire_ohci: IRQ 00000001 AT_req
[  530.655264] firewire_ohci: AT spd 0 tl 07, ffc1 -> ffc0, ack_pending , QR req, fffff0000904
[  530.655793] firewire_ohci: IRQ 00000020 AR_resp
[  530.655797] firewire_ohci: AR spd 0 tl 07, ffc0 -> ffc1, ack_complete, QR resp = c03f3c7a
[  530.690859] firewire_ohci: IRQ 00000080 IR
[  530.722082] firewire_ohci: IRQ 00000080 IR
[  530.753310] firewire_ohci: IRQ 00000080 IR
[  530.784539] firewire_ohci: IRQ 00000080 IR
[  530.815767] firewire_ohci: IRQ 00000080 IR
[  530.846995] firewire_ohci: IRQ 00000080 IR
[  530.878223] firewire_ohci: IRQ 00000080 IR
[  530.909451] firewire_ohci: IRQ 00000080 IR
[  530.940679] firewire_ohci: IRQ 00000080 IR
[  530.971907] firewire_ohci: IRQ 00000080 IR
[  531.003135] firewire_ohci: IRQ 00000080 IR
[  531.034363] firewire_ohci: IRQ 00000080 IR
[  531.065553] firewire_ohci: IRQ 00000080 IR
[  531.096820] firewire_ohci: IRQ 00000080 IR
[  531.128047] firewire_ohci: IRQ 00000080 IR
[  531.159275] firewire_ohci: IRQ 00000080 IR
[  531.190504] firewire_ohci: IRQ 00000080 IR
[  531.221732] firewire_ohci: IRQ 00000080 IR
[  531.252960] firewire_ohci: IRQ 00000080 IR
[  531.284188] firewire_ohci: IRQ 00000080 IR
[  531.315378] firewire_ohci: IRQ 00000080 IR
[  531.346643] firewire_ohci: IRQ 00000080 IR
[  531.377872] firewire_ohci: IRQ 00000080 IR
[  531.409100] firewire_ohci: IRQ 00000080 IR
[  531.440328] firewire_ohci: IRQ 00000080 IR
[  531.471556] firewire_ohci: IRQ 00000080 IR
[  531.502784] firewire_ohci: IRQ 00000080 IR
[  531.534012] firewire_ohci: IRQ 00000080 IR
[  531.565240] firewire_ohci: IRQ 00000080 IR
[  531.596468] firewire_ohci: IRQ 00000080 IR
[  531.627696] firewire_ohci: IRQ 00000080 IR
[  531.658924] firewire_ohci: IRQ 00000080 IR
[  531.690153] firewire_ohci: IRQ 00000080 IR
[  531.721381] firewire_ohci: IRQ 00000080 IR
[  531.752609] firewire_ohci: IRQ 00000080 IR
[  531.783837] firewire_ohci: IRQ 00000080 IR
[  532.073291] firewire_ohci: IRQ 00000001 AT_req
[  532.073298] firewire_ohci: AT spd 0 tl 08, ffc1 -> ffc0, ack_pending , QR req, fffff0000900
[  532.073912] firewire_ohci: IRQ 00000020 AR_resp
[  532.073916] firewire_ohci: AR spd 0 tl 08, ffc0 -> ffc1, ack_complete, QR resp = 3fffff01
[  532.075386] firewire_ohci: IRQ 00000001 AT_req
[  532.075391] firewire_ohci: AT spd 0 tl 09, ffc1 -> ffc0, ack_pending , QR req, fffff0000904
[  532.075918] firewire_ohci: IRQ 00000020 AR_resp
[  532.075922] firewire_ohci: AR spd 0 tl 09, ffc0 -> ffc1, ack_complete, QR resp = c03f3c7a

> For reference, a kernel log of successful video transmission is below. I 
> used "dvgrab -noavc -guid 080046010261a1ff -d 1 -f avi /tmp/foo.avi" 
> with a DCR-TRV120 in camera mode with no tape. (Of course, you would use 
> -guid 00808801035809f1 with your GR-D20E.) Specifying the GUID prevents 
> AV/C probing from cluttering the log. The computer reads '0900 oMPR and 
> '0904 oPCR0 twice, and it sees that there is a broadcast connection on 
> channel 63. At this time it will modify its own iPCR, but there is no 
> Firewire transaction for this. Then the live video is received in a 
> series of isochronous packets. Finally it reads oMPR and oPCR0 again - I 
> don't know why. The dvgrab console output is ""/tmp/foo001.avi":     
> 3.62 MiB 30 frames timecode 45:85:85.45 date 2024.01.17 02:09:26".

Thanks for the hints and the reference. It does generate cleaner and 
more readable logs this way. I also didn't know one can just capture 
from camera mode through firewire, which simplifies things.

This is a typical failed capture attempt on newer kernels (6.7):
$ dvgrab -noavc -guid 00808801035809f1 -d 1
libiec61883 warning: Transmission node has no plugs online!
Established connection over channel 63
Waiting for DV...
^C""     0.00 MiB 0 frames
Capture Stopped
Error: no DV

[ 3313.954351] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[ 3313.954373] firewire_ohci 0000:01:03.0: AT spd 0 tl 34, ffc1 -> ffc0, ack_pending , QR req, fffff0000900
[ 3313.955278] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[ 3313.955291] firewire_ohci 0000:01:03.0: AR spd 0 tl 34, ffc0 -> ffc1, ack_complete, QR resp = 3fffff01
[ 3313.955345] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[ 3313.955351] firewire_ohci 0000:01:03.0: AT spd 0 tl 35, ffc1 -> ffc0, ack_pending , QR req, fffff0000904
[ 3313.956255] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[ 3313.956261] firewire_ohci 0000:01:03.0: AR spd 0 tl 35, ffc0 -> ffc1, ack_complete, QR resp = 003f007a
[ 3313.956550] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[ 3313.956555] firewire_ohci 0000:01:03.0: AT spd 0 tl 36, ffc1 -> ffc0, ack_pending , QR req, fffff0000900
[ 3313.957262] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[ 3313.957266] firewire_ohci 0000:01:03.0: AR spd 0 tl 36, ffc0 -> ffc1, ack_complete, QR resp = 3fffff01
[ 3313.958787] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[ 3313.958791] firewire_ohci 0000:01:03.0: AT spd 0 tl 37, ffc1 -> ffc0, ack_pending , QR req, fffff0000904
[ 3313.959260] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[ 3313.959264] firewire_ohci 0000:01:03.0: AR spd 0 tl 37, ffc0 -> ffc1, ack_complete, QR resp = 003f007a
^C
[ 3615.686380] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[ 3615.686393] firewire_ohci 0000:01:03.0: AT spd 0 tl 39, ffc1 -> ffc0, ack_pending , QR req, fffff0000900
[ 3615.686700] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[ 3615.686706] firewire_ohci 0000:01:03.0: AR spd 0 tl 39, ffc0 -> ffc1, ack_complete, QR resp = 3fffff01
[ 3615.688323] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[ 3615.688329] firewire_ohci 0000:01:03.0: AT spd 0 tl 3a, ffc1 -> ffc0, ack_pending , QR req, fffff0000904
[ 3615.688716] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[ 3615.688723] firewire_ohci 0000:01:03.0: AR spd 0 tl 3a, ffc0 -> ffc1, ack_complete, QR resp = 003f007a

That said, something interesting happened while testing.
I was able to get a capture with kernel 6.7 out of pure luck. Luckily I 
did have logging enabled when it happened. I ran dvgrab, it hung for 
about 5 seconds, and then there was a reset and it started capturing!

[  310.458176] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  310.458188] firewire_ohci 0000:01:03.0: AT spd 0 tl 3d, ffc1 -> ffc0, ack_pending , QR req, fffff0000900
[  310.458501] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  310.458507] firewire_ohci 0000:01:03.0: AR spd 0 tl 3d, ffc0 -> ffc1, ack_complete, QR resp = 3fffff01
[  310.458537] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  310.458541] firewire_ohci 0000:01:03.0: AT spd 0 tl 3e, ffc1 -> ffc0, ack_pending , QR req, fffff0000904
[  310.459484] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  310.459488] firewire_ohci 0000:01:03.0: AR spd 0 tl 3e, ffc0 -> ffc1, ack_complete, QR resp = 003f007a
[  310.459760] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  310.459765] firewire_ohci 0000:01:03.0: AT spd 0 tl 3f, ffc1 -> ffc0, ack_pending , QR req, fffff0000900
[  310.460496] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  310.460501] firewire_ohci 0000:01:03.0: AR spd 0 tl 3f, ffc0 -> ffc1, ack_complete, QR resp = 3fffff01
[  310.462244] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  310.462250] firewire_ohci 0000:01:03.0: AT spd 0 tl 00, ffc1 -> ffc0, ack_pending , QR req, fffff0000904
[  310.462495] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  310.462501] firewire_ohci 0000:01:03.0: AR spd 0 tl 00, ffc0 -> ffc1, ack_complete, QR resp = 003f007a
[  314.728317] firewire_ohci 0000:01:03.0: IRQ 00000010 AR_req
[  314.728331] firewire_ohci 0000:01:03.0: AR evt_bus_reset, generation 22
[  314.728494] firewire_ohci 0000:01:03.0: IRQ 00010000 selfID
[  314.728507] firewire_ohci 0000:01:03.0: 2 selfIDs, generation 22, local node ID ffc1
[  314.728510] firewire_ohci 0000:01:03.0: selfID 0: 807f0882, phy 0 [p..] S100 gc=63 +0W Lci
[  314.728514] firewire_ohci 0000:01:03.0: selfID 0: 817f8cd0, phy 1 [c-.] S400 gc=63 -3W Lc
[  314.728531] firewire_core 0000:01:03.0: phy config: new root=ffc1, gap_count=5
[  314.728542] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  314.728546] firewire_ohci 0000:01:03.0: AT ack_complete, PHY 01c50000 fe3affff
[  314.728559] firewire_ohci 0000:01:03.0: IRQ 00000010 AR_req
[  314.728563] firewire_ohci 0000:01:03.0: AR evt_bus_reset, generation 23
[  314.728565] firewire_ohci 0000:01:03.0: AR evt_bus_reset, generation 23
[  314.728733] firewire_ohci 0000:01:03.0: IRQ 00010000 selfID
[  314.728745] firewire_ohci 0000:01:03.0: 2 selfIDs, generation 24, local node ID ffc1
[  314.728747] firewire_ohci 0000:01:03.0: selfID 0: 80450880, phy 0 [p..] S100 gc=5 +0W Lc
[  314.728750] firewire_ohci 0000:01:03.0: selfID 0: 81458cd2, phy 1 [c-.] S400 gc=5 -3W Lci
[  315.253932] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.253945] firewire_ohci 0000:01:03.0: AT spd 0 tl 04, ffc1 -> ffc0, ack_pending , QR req, fffff0000400
[  315.253983] firewire_core 0000:01:03.0: rediscovered device fw0
[  315.253990] firewire_core 0000:01:03.0: giving up on refresh of device fw1: bus reset
[  315.254817] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.254823] firewire_ohci 0000:01:03.0: AR spd 0 tl 04, ffc0 -> ffc1, ack_complete, QR resp = 0426907c
[  315.254839] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.254844] firewire_ohci 0000:01:03.0: AT spd 0 tl 1e, ffc1 -> ffc0, ack_pending , QR req, fffff0000404
[  315.255809] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.255813] firewire_ohci 0000:01:03.0: AR spd 0 tl 1e, ffc0 -> ffc1, ack_complete, QR resp = 31333934
[  315.255829] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.255833] firewire_ohci 0000:01:03.0: AT spd 0 tl 1f, ffc1 -> ffc0, ack_pending , QR req, fffff0000408
[  315.256851] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.256855] firewire_ohci 0000:01:03.0: AR spd 0 tl 1f, ffc0 -> ffc1, ack_complete, QR resp = e0644000
[  315.256871] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.256875] firewire_ohci 0000:01:03.0: AT spd 0 tl 20, ffc1 -> ffc0, ack_pending , QR req, fffff000040c
[  315.257800] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.257805] firewire_ohci 0000:01:03.0: AR spd 0 tl 20, ffc0 -> ffc1, ack_complete, QR resp = 00808801
[  315.257821] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.257825] firewire_ohci 0000:01:03.0: AT spd 0 tl 21, ffc1 -> ffc0, ack_pending , QR req, fffff0000410
[  315.258807] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.258813] firewire_ohci 0000:01:03.0: AR spd 0 tl 21, ffc0 -> ffc1, ack_complete, QR resp = 035809f1
[  315.258831] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.258835] firewire_ohci 0000:01:03.0: AT spd 0 tl 22, ffc1 -> ffc0, ack_pending , QR req, fffff0000414
[  315.259909] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.259914] firewire_ohci 0000:01:03.0: AR spd 0 tl 22, ffc0 -> ffc1, ack_complete, QR resp = 0008c442
[  315.259930] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.259935] firewire_ohci 0000:01:03.0: AT spd 0 tl 23, ffc1 -> ffc0, ack_pending , QR req, fffff0000418
[  315.260827] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.260833] firewire_ohci 0000:01:03.0: AR spd 0 tl 23, ffc0 -> ffc1, ack_complete, QR resp = 03008088
[  315.260850] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.260854] firewire_ohci 0000:01:03.0: AT spd 0 tl 24, ffc1 -> ffc0, ack_pending , QR req, fffff000041c
[  315.261817] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.261822] firewire_ohci 0000:01:03.0: AR spd 0 tl 24, ffc0 -> ffc1, ack_complete, QR resp = 8100000f
[  315.261838] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.261842] firewire_ohci 0000:01:03.0: AT spd 0 tl 25, ffc1 -> ffc0, ack_pending , QR req, fffff0000420
[  315.262811] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.262817] firewire_ohci 0000:01:03.0: AR spd 0 tl 25, ffc0 -> ffc1, ack_complete, QR resp = 0c0083c0
[  315.262838] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.262842] firewire_ohci 0000:01:03.0: AT spd 0 tl 26, ffc1 -> ffc0, ack_pending , QR req, fffff0000424
[  315.263812] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.263817] firewire_ohci 0000:01:03.0: AR spd 0 tl 26, ffc0 -> ffc1, ack_complete, QR resp = d1000005
[  315.263838] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.263842] firewire_ohci 0000:01:03.0: AT spd 0 tl 27, ffc1 -> ffc0, ack_pending , QR req, fffff0000428
[  315.264958] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.264964] firewire_ohci 0000:01:03.0: AR spd 0 tl 27, ffc0 -> ffc1, ack_complete, QR resp = 8d000013
[  315.264980] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.264985] firewire_ohci 0000:01:03.0: AT spd 0 tl 28, ffc1 -> ffc0, ack_pending , QR req, fffff000042c
[  315.265859] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.265864] firewire_ohci 0000:01:03.0: AR spd 0 tl 28, ffc0 -> ffc1, ack_complete, QR resp = c3000008
[  315.265880] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.265885] firewire_ohci 0000:01:03.0: AT spd 0 tl 29, ffc1 -> ffc0, ack_pending , QR req, fffff0000430
[  315.266920] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.266927] firewire_ohci 0000:01:03.0: AR spd 0 tl 29, ffc0 -> ffc1, ack_complete, QR resp = 1701006b
[  315.266946] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.266950] firewire_ohci 0000:01:03.0: AT spd 0 tl 2a, ffc1 -> ffc0, ack_pending , QR req, fffff0000434
[  315.267846] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.267852] firewire_ohci 0000:01:03.0: AR spd 0 tl 2a, ffc0 -> ffc1, ack_complete, QR resp = 81000013
[  315.267869] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.267874] firewire_ohci 0000:01:03.0: AT spd 0 tl 2b, ffc1 -> ffc0, ack_pending , QR req, fffff0000480
[  315.268803] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.268807] firewire_ohci 0000:01:03.0: AR spd 0 tl 2b, ffc0 -> ffc1, ack_complete, QR resp = 0006c2ad
[  315.268824] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.268828] firewire_ohci 0000:01:03.0: AT spd 0 tl 2c, ffc1 -> ffc0, ack_pending , QR req, fffff0000484
[  315.269801] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.269805] firewire_ohci 0000:01:03.0: AR spd 0 tl 2c, ffc0 -> ffc1, ack_complete, QR resp = 00000000
[  315.269821] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.269826] firewire_ohci 0000:01:03.0: AT spd 0 tl 2d, ffc1 -> ffc0, ack_pending , QR req, fffff0000488
[  315.270814] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.270820] firewire_ohci 0000:01:03.0: AR spd 0 tl 2d, ffc0 -> ffc1, ack_complete, QR resp = 00000000
[  315.270839] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.270844] firewire_ohci 0000:01:03.0: AT spd 0 tl 2e, ffc1 -> ffc0, ack_pending , QR req, fffff000048c
[  315.271830] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.271834] firewire_ohci 0000:01:03.0: AR spd 0 tl 2e, ffc0 -> ffc1, ack_complete, QR resp = 47522d44
[  315.271851] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.271855] firewire_ohci 0000:01:03.0: AT spd 0 tl 2f, ffc1 -> ffc0, ack_pending , QR req, fffff0000490
[  315.273053] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.273058] firewire_ohci 0000:01:03.0: AR spd 0 tl 2f, ffc0 -> ffc1, ack_complete, QR resp = 32300000
[  315.273075] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.273080] firewire_ohci 0000:01:03.0: AT spd 0 tl 30, ffc1 -> ffc0, ack_pending , QR req, fffff0000494
[  315.273807] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.273812] firewire_ohci 0000:01:03.0: AR spd 0 tl 30, ffc0 -> ffc1, ack_complete, QR resp = 00000000
[  315.273829] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.273834] firewire_ohci 0000:01:03.0: AT spd 0 tl 31, ffc1 -> ffc0, ack_pending , QR req, fffff0000498
[  315.274814] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.274820] firewire_ohci 0000:01:03.0: AR spd 0 tl 31, ffc0 -> ffc1, ack_complete, QR resp = 00000000
[  315.274838] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.274842] firewire_ohci 0000:01:03.0: AT spd 0 tl 32, ffc1 -> ffc0, ack_pending , QR req, fffff000044c
[  315.275807] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.275812] firewire_ohci 0000:01:03.0: AR spd 0 tl 32, ffc0 -> ffc1, ack_complete, QR resp = 0002ad09
[  315.275827] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.275832] firewire_ohci 0000:01:03.0: AT spd 0 tl 33, ffc1 -> ffc0, ack_pending , QR req, fffff0000450
[  315.276818] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.276822] firewire_ohci 0000:01:03.0: AR spd 0 tl 33, ffc0 -> ffc1, ack_complete, QR resp = 1701006b
[  315.276839] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.276843] firewire_ohci 0000:01:03.0: AT spd 0 tl 34, ffc1 -> ffc0, ack_pending , QR req, fffff0000454
[  315.277862] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.277866] firewire_ohci 0000:01:03.0: AR spd 0 tl 34, ffc0 -> ffc1, ack_complete, QR resp = 8100000b
[  315.277883] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.277887] firewire_ohci 0000:01:03.0: AT spd 0 tl 35, ffc1 -> ffc0, ack_pending , QR req, fffff0000480
[  315.278814] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.278819] firewire_ohci 0000:01:03.0: AR spd 0 tl 35, ffc0 -> ffc1, ack_complete, QR resp = 0006c2ad
[  315.278837] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.278842] firewire_ohci 0000:01:03.0: AT spd 0 tl 36, ffc1 -> ffc0, ack_pending , QR req, fffff0000484
[  315.279887] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.279891] firewire_ohci 0000:01:03.0: AR spd 0 tl 36, ffc0 -> ffc1, ack_complete, QR resp = 00000000
[  315.279907] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.279911] firewire_ohci 0000:01:03.0: AT spd 0 tl 37, ffc1 -> ffc0, ack_pending , QR req, fffff0000488
[  315.280806] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.280812] firewire_ohci 0000:01:03.0: AR spd 0 tl 37, ffc0 -> ffc1, ack_complete, QR resp = 00000000
[  315.280830] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.280835] firewire_ohci 0000:01:03.0: AT spd 0 tl 38, ffc1 -> ffc0, ack_pending , QR req, fffff000048c
[  315.281819] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.281823] firewire_ohci 0000:01:03.0: AR spd 0 tl 38, ffc0 -> ffc1, ack_complete, QR resp = 47522d44
[  315.281839] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.281843] firewire_ohci 0000:01:03.0: AT spd 0 tl 39, ffc1 -> ffc0, ack_pending , QR req, fffff0000490
[  315.282811] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.282817] firewire_ohci 0000:01:03.0: AR spd 0 tl 39, ffc0 -> ffc1, ack_complete, QR resp = 32300000
[  315.282838] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.282842] firewire_ohci 0000:01:03.0: AT spd 0 tl 3a, ffc1 -> ffc0, ack_pending , QR req, fffff0000494
[  315.283813] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.283818] firewire_ohci 0000:01:03.0: AR spd 0 tl 3a, ffc0 -> ffc1, ack_complete, QR resp = 00000000
[  315.284289] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.284294] firewire_ohci 0000:01:03.0: AT spd 0 tl 3b, ffc1 -> ffc0, ack_pending , QR req, fffff0000498
[  315.284963] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.284969] firewire_ohci 0000:01:03.0: AR spd 0 tl 3b, ffc0 -> ffc1, ack_complete, QR resp = 00000000
[  315.285006] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.285011] firewire_ohci 0000:01:03.0: AT spd 0 tl 3c, ffc1 -> ffc0, ack_pending , QR req, fffff0000474
[  315.285890] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.285895] firewire_ohci 0000:01:03.0: AR spd 0 tl 3c, ffc0 -> ffc1, ack_complete, QR resp = 0002f1df
[  315.285925] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.285930] firewire_ohci 0000:01:03.0: AT spd 0 tl 3d, ffc1 -> ffc0, ack_pending , QR req, fffff0000478
[  315.286939] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.286945] firewire_ohci 0000:01:03.0: AR spd 0 tl 3d, ffc0 -> ffc1, ack_complete, QR resp = 00808801
[  315.286963] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.286967] firewire_ohci 0000:01:03.0: AT spd 0 tl 3e, ffc1 -> ffc0, ack_pending , QR req, fffff000047c
[  315.287818] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.287823] firewire_ohci 0000:01:03.0: AR spd 0 tl 3e, ffc0 -> ffc1, ack_complete, QR resp = 035809f1
[  315.287840] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.287845] firewire_ohci 0000:01:03.0: AT spd 0 tl 3f, ffc1 -> ffc0, ack_pending , QR req, fffff0000438
[  315.288807] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.288812] firewire_ohci 0000:01:03.0: AR spd 0 tl 3f, ffc0 -> ffc1, ack_complete, QR resp = 00043327
[  315.288829] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.288833] firewire_ohci 0000:01:03.0: AT spd 0 tl 00, ffc1 -> ffc0, ack_pending , QR req, fffff000043c
[  315.289803] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.289807] firewire_ohci 0000:01:03.0: AR spd 0 tl 00, ffc0 -> ffc1, ack_complete, QR resp = 1200a02d
[  315.289823] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.289828] firewire_ohci 0000:01:03.0: AT spd 0 tl 01, ffc1 -> ffc0, ack_pending , QR req, fffff0000440
[  315.290816] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.290822] firewire_ohci 0000:01:03.0: AR spd 0 tl 01, ffc0 -> ffc1, ack_complete, QR resp = 13010001
[  315.290948] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.290953] firewire_ohci 0000:01:03.0: AT spd 0 tl 02, ffc1 -> ffc0, ack_pending , QR req, fffff0000444
[  315.291828] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.291833] firewire_ohci 0000:01:03.0: AR spd 0 tl 02, ffc0 -> ffc1, ack_complete, QR resp = 1701006b
[  315.291851] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.291855] firewire_ohci 0000:01:03.0: AT spd 0 tl 03, ffc1 -> ffc0, ack_pending , QR req, fffff0000448
[  315.293038] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.293043] firewire_ohci 0000:01:03.0: AR spd 0 tl 03, ffc0 -> ffc1, ack_complete, QR resp = 8100000e
[  315.293059] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.293064] firewire_ohci 0000:01:03.0: AT spd 0 tl 04, ffc1 -> ffc0, ack_pending , QR req, fffff0000480
[  315.293821] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.293825] firewire_ohci 0000:01:03.0: AR spd 0 tl 04, ffc0 -> ffc1, ack_complete, QR resp = 0006c2ad
[  315.293841] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.293846] firewire_ohci 0000:01:03.0: AT spd 0 tl 05, ffc1 -> ffc0, ack_pending , QR req, fffff0000484
[  315.294828] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.294834] firewire_ohci 0000:01:03.0: AR spd 0 tl 05, ffc0 -> ffc1, ack_complete, QR resp = 00000000
[  315.294852] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.294856] firewire_ohci 0000:01:03.0: AT spd 0 tl 06, ffc1 -> ffc0, ack_pending , QR req, fffff0000488
[  315.295821] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.295826] firewire_ohci 0000:01:03.0: AR spd 0 tl 06, ffc0 -> ffc1, ack_complete, QR resp = 00000000
[  315.295844] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.295848] firewire_ohci 0000:01:03.0: AT spd 0 tl 07, ffc1 -> ffc0, ack_pending , QR req, fffff000048c
[  315.296832] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.296836] firewire_ohci 0000:01:03.0: AR spd 0 tl 07, ffc0 -> ffc1, ack_complete, QR resp = 47522d44
[  315.296851] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.296856] firewire_ohci 0000:01:03.0: AT spd 0 tl 08, ffc1 -> ffc0, ack_pending , QR req, fffff0000490
[  315.297811] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.297815] firewire_ohci 0000:01:03.0: AR spd 0 tl 08, ffc0 -> ffc1, ack_complete, QR resp = 32300000
[  315.297831] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.297835] firewire_ohci 0000:01:03.0: AT spd 0 tl 09, ffc1 -> ffc0, ack_pending , QR req, fffff0000494
[  315.298819] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.298825] firewire_ohci 0000:01:03.0: AR spd 0 tl 09, ffc0 -> ffc1, ack_complete, QR resp = 00000000
[  315.298842] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.298847] firewire_ohci 0000:01:03.0: AT spd 0 tl 0a, ffc1 -> ffc0, ack_pending , QR req, fffff0000498
[  315.299891] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.299896] firewire_ohci 0000:01:03.0: AR spd 0 tl 0a, ffc0 -> ffc1, ack_complete, QR resp = 00000000
[  315.299912] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.299916] firewire_ohci 0000:01:03.0: AT spd 0 tl 0b, ffc1 -> ffc0, ack_pending , QR req, fffff0000458
[  315.300810] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.300816] firewire_ohci 0000:01:03.0: AR spd 0 tl 0b, ffc0 -> ffc1, ack_complete, QR resp = 0006c930
[  315.300840] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.300844] firewire_ohci 0000:01:03.0: AT spd 0 tl 0c, ffc1 -> ffc0, ack_pending , QR req, fffff000045c
[  315.301828] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.301835] firewire_ohci 0000:01:03.0: AR spd 0 tl 0c, ffc0 -> ffc1, ack_complete, QR resp = 00000000
[  315.302987] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.302994] firewire_ohci 0000:01:03.0: AT spd 0 tl 0d, ffc1 -> ffc0, ack_pending , QR req, fffff0000460
[  315.303804] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.303809] firewire_ohci 0000:01:03.0: AR spd 0 tl 0d, ffc0 -> ffc1, ack_complete, QR resp = 00000000
[  315.303827] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.303831] firewire_ohci 0000:01:03.0: AT spd 0 tl 0e, ffc1 -> ffc0, ack_pending , QR req, fffff0000464
[  315.304983] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.304989] firewire_ohci 0000:01:03.0: AR spd 0 tl 0e, ffc0 -> ffc1, ack_complete, QR resp = 4a564300
[  315.305006] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.305010] firewire_ohci 0000:01:03.0: AT spd 0 tl 0f, ffc1 -> ffc0, ack_pending , QR req, fffff0000468
[  315.305895] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.305910] firewire_ohci 0000:01:03.0: AR spd 0 tl 0f, ffc0 -> ffc1, ack_complete, QR resp = 00000000
[  315.305940] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.305945] firewire_ohci 0000:01:03.0: AT spd 0 tl 10, ffc1 -> ffc0, ack_pending , QR req, fffff000046c
[  315.306954] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.306961] firewire_ohci 0000:01:03.0: AR spd 0 tl 10, ffc0 -> ffc1, ack_complete, QR resp = 00000000
[  315.306979] firewire_ohci 0000:01:03.0: IRQ 00000001 AT_req
[  315.306984] firewire_ohci 0000:01:03.0: AT spd 0 tl 11, ffc1 -> ffc0, ack_pending , QR req, fffff0000470
[  315.307848] firewire_ohci 0000:01:03.0: IRQ 00000020 AR_resp
[  315.307852] firewire_ohci 0000:01:03.0: AR spd 0 tl 11, ffc0 -> ffc1, ack_complete, QR resp = 00000000
[  315.307862] firewire_core 0000:01:03.0: rediscovered device fw1
[  317.053817] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.085103] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.116352] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.147606] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.178855] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.210102] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.241352] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.272601] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.303850] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.335100] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.366349] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.397599] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.428848] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.460098] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.491347] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.522597] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.553847] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.585096] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.616346] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.647595] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.678845] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.710094] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.741344] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.772594] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.803843] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.835093] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.866342] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.897592] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.928841] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.960091] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  317.991341] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  318.022590] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  318.053840] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  318.085090] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  318.116301] firewire_ohci 0000:01:03.0: IRQ 00000080 IR
[  318.147590] firewire_ohci 0000:01:03.0: IRQ 00000080 IR

I have not been able to get it to work since, after multiple attempts. I 
even tried resetting the device with raw1394_reset_bus_new() using both 
reset types while dvgrab is waiting, and it hasn't changed anything. At 
the moment I suspect there might be a race somewhere.

Thanks

--
Tasos

Re: Question regarding linux1394 and bug report

[Tasos S. <ta...@ta...>]

Hi,

Thank you for your response. It is much appreciated. Apologies for the
late reply; I was hoping to respond after I've discovered something new
as I don't want to create noise, but I haven't made much progress.

On 2024-01-05 17:02, Takashi Sakamoto wrote:
> Hi,
> 
> I'm not good at any type of video protocol over IEEE 1394, thus less help
> to your issue, sorry.
> 
> As a quick glance, you need to identify the direct cause of your issue
> that dvgrab never receives video data at recent version of kernel at
> first, then go to investigate kernel implementation if needed.
> 
> In my opinion, the best way is to investigate whether dvgrab (and
> libavc1394) can operate your hardware to transfer isochronous packet
> to your system.

Indeed. I attempted that by reading through the source code and
following the chain of libraries but I got lost really quickly.

> For example, you have dumped the part of communication between dvgrab
> and your hardware for AV/C commands. You can interpret them according to
> specification specific to tape recorder and player protocol. You can see
> two documents in 1394TA site archived by internet-archive project[1].
> 
> * AV/C Digital Interface Command Set General Specification Version 4.2
>   (2004006)
> * AV/C Tape Recorder/Player Subunit Specification 2.4 (2004005)

Thank you very much for linking those documents. I searched online for
the documents in my attempt to understand the communication but I was
unable to locate them. This helps a lot!

> Below communication expresses:
> 
> ```
>  firewire_ohci: AT spd 0 tl 2a, ffc1 -> ffc0, ack_complete, QW req, fffff0000b00 = 0120d07f
>  firewire_ohci: AR spd 0 tl 2a, ffc0 -> ffc1, ack_pending , QW req, fffff0000d00 = 0c20c460
>  firewire_ohci: AT spd 0 tl 2a, ffc1 -> ffc0, ack_complete, W resp
> ```
> 
> [dvgrab -> hardware]
> 0x01: command type:    status
> 0x20: subunit type/id: tape recorder/player
> 0xd0: opcode:          transport state: 
> 0x7f: operand[0]:      0x7e
> 
> [hardware -> dvgrab]
> 0x0c: response: stable
> 0x20: subunit type/id: tape recorder/player
> 0xc4: opcode:          transport_mode:  wind
> 0x60: operand[0]:      transport_state: stop
> 
> Below communication expresses:
> 
> ```
>  firewire_ohci: AT spd 0 tl 2d, ffc1 -> ffc0, ack_complete, QW req, fffff0000b00 = 0020c375
>  firewire_ohci: AR spd 0 tl 2d, ffc0 -> ffc1, ack_pending , QW req, fffff0000d00 = 0920c375
>  firewire_ohci: AT spd 0 tl 2d, ffc1 -> ffc0, ack_complete, W resp
> ```
> 
> [dvgrab -> hardware]
> 0x00: command type:    control
> 0x20: subunit type/id: tape recorder/player
> 0xc3: opcode:          play
> 0x75: operand[0]:      playback_mode: forward
> 
> [hardware -> dvgrab]
> 0x09: response:        accepted
> 0x20: subunit type/id: tape recorder/player
> 0xc3: opcode:          play
> 0x75: operand[0]:      playback_mode: forward
> 
> 
> I expect that if dvgrab takes the hardware to be prepared, it
> keeps isochronous resources by operating both CHANNEL_AVAILABLE registers
> (0xfffff0000224-0228) and BANDWIDTH_AVAILABLE register (0xfffff0000220),
> and operate plug control registers (0xfffff0000900-0904) according to
> IEC 61883-1. Then the hardware start transmission of isochronous
> packets, defined in IEC 61883-1 and -2/-3/-5.
> 

Understood. Thanks for the detailed explanation!

> [1] https://web.archive.org/web/20200204014929/1394ta.org/specifications/
> 
> 
> Regards
> 
> Takashi Sakamoto

Re: Question regarding linux1394 and bug report

[Adam G. <ad...@po...>]

Hi Tasos,

Are you sure 2.6.35-rc3 is working? The "fw_working" log doesn't appear 
to include any video transmission.

For reference, a kernel log of successful video transmission is below. I 
used "dvgrab -noavc -guid 080046010261a1ff -d 1 -f avi /tmp/foo.avi" 
with a DCR-TRV120 in camera mode with no tape. (Of course, you would use 
-guid 00808801035809f1 with your GR-D20E.) Specifying the GUID prevents 
AV/C probing from cluttering the log. The computer reads '0900 oMPR and 
'0904 oPCR0 twice, and it sees that there is a broadcast connection on 
channel 63. At this time it will modify its own iPCR, but there is no 
Firewire transaction for this. Then the live video is received in a 
series of isochronous packets. Finally it reads oMPR and oPCR0 again - I 
don't know why. The dvgrab console output is ""/tmp/foo001.avi":     
3.62 MiB 30 frames timecode 45:85:85.45 date 2024.01.17 02:09:26".


[ 3071.907306] firewire_ohci 0000:02:00.0: IRQ 00000021 AR_resp AT_req
[ 3071.908198] firewire_ohci 0000:02:00.0: AR spd 0 tl 29, ffc0 -> ffc1, ack_complete, QR resp = 3fffff01
[ 3071.908933] firewire_ohci 0000:02:00.0: AT spd 0 tl 29, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000900
[ 3071.909872] firewire_ohci 0000:02:00.0: IRQ 00000021 AR_resp AT_req
[ 3071.910637] firewire_ohci 0000:02:00.0: AR spd 0 tl 2a, ffc0 -> ffc1, ack_complete, QR resp = c03f3c7a
[ 3071.911367] firewire_ohci 0000:02:00.0: AT spd 0 tl 2a, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000904
[ 3071.916497] firewire_ohci 0000:02:00.0: IRQ 00000021 AR_resp AT_req
[ 3071.917394] firewire_ohci 0000:02:00.0: AR spd 0 tl 2b, ffc0 -> ffc1, ack_complete, QR resp = 3fffff01
[ 3071.918160] firewire_ohci 0000:02:00.0: AT spd 0 tl 2b, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000900
[ 3071.920769] firewire_ohci 0000:02:00.0: IRQ 00000001 AT_req
[ 3071.921708] firewire_ohci 0000:02:00.0: IRQ 00000020 AR_resp
[ 3071.922565] firewire_ohci 0000:02:00.0: AT spd 0 tl 2c, ffc1 -> ffc0, ack_pending , QR req, fffff0000904
[ 3071.923424] firewire_ohci 0000:02:00.0: AR spd 0 tl 2c, ffc0 -> ffc1, ack_complete, QR resp = c03f3c7a
[ 3071.970373] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.001624] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.032874] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.064133] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.095369] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.126625] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.157879] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.189119] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.220383] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.251631] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.282874] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.314132] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.345378] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.376624] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.407877] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.439120] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.470386] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.501620] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.532878] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.564137] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.595372] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.626629] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.657873] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.689137] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.720373] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.751628] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.782883] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.814083] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.845379] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.876629] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.907890] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.939125] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3072.970382] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3073.001640] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3073.032889] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3073.064094] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3073.095385] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3073.126640] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3073.157886] firewire_ohci 0000:02:00.0: IRQ 00000080 IR
[ 3073.163316] firewire_ohci 0000:02:00.0: IRQ 00000021 AR_resp AT_req
[ 3073.164037] firewire_ohci 0000:02:00.0: AR spd 0 tl 2d, ffc0 -> ffc1, ack_complete, QR resp = 3fffff01
[ 3073.164616] firewire_ohci 0000:02:00.0: AT spd 0 tl 2d, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000900
[ 3073.167216] firewire_ohci 0000:02:00.0: IRQ 00000021 AR_resp AT_req
[ 3073.167912] firewire_ohci 0000:02:00.0: AR spd 0 tl 2e, ffc0 -> ffc1, ack_complete, QR resp = c03f3c7a
[ 3073.168481] firewire_ohci 0000:02:00.0: AT spd 0 tl 2e, ffc1 -> ffc0, pending/cancelled, QR req, fffff0000904


-- Adam

Re: Hard crash when loading firewire-ohci

[Takashi S. <o-t...@sa...>]

Hi,

On Tue, Jan 16, 2024 at 10:38:38PM +0100, Tobias Gruetzmacher wrote:
> The unfortunate truth is that the Asmedia bridge and the 1394 live on
> the same PCIe card (Amazon said it was this one:
> https://www.amazon.de/gp/product/B07S9G4XGB) and I was under the
> impression that is the only way to get Firewire ports on modern hardware
> (which only has PCIe slots) - Or do "native" PCIe Firewire cards exist?

In the market, You can find such cards with:

* Texas Instruments XIO2221 (integrating PCIe-PCI bridge)
* Texas Instruments XIO2213 (integrating PCIe-PCI bridge)
* Texas Instruments XIO2200 (integrating PCIe-PCI bridge)
* LSI FW643
* VIA VT6315


Regards

Takashi Sakamoto

Re: Hard crash when loading firewire-ohci

[Tobias G. <tob...@23...>]

Hi,

thank you very much. I was able to verify with 6.6.11 that the crash is
indeed gone.

Meanwhile I learned through the retronetworking community
(https://osmocom.org/projects/retronetworking/wiki/PCIe-%3EPCI_bridges)
that those Asmedia PCI bridges are indeed known for interrupt
problems...

The unfortunate truth is that the Asmedia bridge and the 1394 live on
the same PCIe card (Amazon said it was this one:
https://www.amazon.de/gp/product/B07S9G4XGB) and I was under the
impression that is the only way to get Firewire ports on modern hardware
(which only has PCIe slots) - Or do "native" PCIe Firewire cards exist?

Regards, Tobias

On Tue, Jan 16, 2024 at 10:52:35AM +0900, Takashi Sakamoto wrote:
> Hi,
> 
> The change for 1394 OHCI driver, aimed at suppressing the unexpected
> system reboot in AMD Ryzen machine[1], has been merged into Linux kernel
> v6.7[2]. It has also been applied to the following releases of stable and
> longterm kernels.
> 
> * 6.6.11[3]
> * 6.1.72[4]
> * 5.15.147[5]
> * 5.10.208[6]
> * 5.4.267[7]
> * 4.19.305[8]
> * 4.14.336[9]
> 
> Once the downstream distribution project provides the corresponding kernel
> packages, you should no longer encounter the unexpected system reboot.
> 
> Note that the following combination of hardware is not necessarily suitable,
> depending on your use case:
> 
> * Any type of AMD Ryzen machine
> * 1394 OHCI hardware consists of:
>     * Asmedia ASM1083/1085
>     * VIA VT6306/6307/6308
> 
> When working with time-aware protocol, such as audio sample processing, it
> is advisable to avoid the combination. The change accompanies a functional
> limitation that the software stack does not provides precise hardware time
> in this case.
> 
> If you choose to continue using AMD Ryzen machine, the recommendation is
> to replace the 1394 OHCI hardware with another one. Conversely, if you
> choose to continue using the 1394 OHCI hardware, the recommendation is to
> use the machine provided by vendors other than AMD.
> 
> Thanks for your report and long patience.
> 
> [1] https://git.kernel.org/torvalds/linux/c/ac9184fbb847
> [2] https://lore.kernel.org/lkml/CAHk-=wid...@ma.../
> [3] https://lore.kernel.org/lkml/2024011058-sheep-thrower-d2f8@gregkh/
> [4] https://lore.kernel.org/lkml/2024011052-unsightly-bronze-e628@gregkh/
> [5] https://lore.kernel.org/lkml/2024011541-defective-scuff-c55e@gregkh/
> [6] https://lore.kernel.org/lkml/2024011532-lustiness-hybrid-fc72@gregkh/
> [7] https://lore.kernel.org/lkml/2024011519-mating-tag-1f62@gregkh/
> [8] https://lore.kernel.org/lkml/2024011508-shakiness-resonant-f15e@gregkh/
> [9] https://lore.kernel.org/lkml/2024011046-ecology-tiptoeing-ce50@gregkh/
> 
> On Tue, Dec 12, 2023 at 01:13:40AM +0100, Tobias Gruetzmacher wrote:
> > [Resend because I wasn't subcribed before]
> > 
> > Hi,
> > 
> > in recent kernels (noticed with Debian kernel 6.5) I get a hard crash
> > when the firewire-ohci module is loaded.
> > 
> > I could bisect this issue to commit
> > 
> > dcadfd7f7c74ef9ee415e072a19bdf6c085159eb is the first bad commit
> > commit dcadfd7f7c74ef9ee415e072a19bdf6c085159eb
> > Author: Takashi Sakamoto <o-t...@sa...>
> > Date:   Tue May 30 08:12:40 2023 +0900
> > 
> >     firewire: core: use union for callback of transaction completion
> > 
> > But I'm not sure how to continue debugging from here, since I don't get
> > any output after
> > 
> > [Dec10 19:17] firewire_ohci 0000:0b:00.0: enabling device (0000 -> 0003)
> > [  +0.075791] firewire_ohci 0000:0b:00.0: added OHCI v1.0 device as card 0, 4 IR + 8 IT contexts, quirks 0x11
> > 
> > My hardware is:
> > 
> > 0b:00.0 FireWire (IEEE 1394): VIA Technologies, Inc. VT6306/7/8 [Fire II(M)] IEEE 1394 OHCI Controller (rev c0) (prog-if 10 [OHCI])
> >         Subsystem: VIA Technologies, Inc. VT6306/7/8 [Fire II(M)] IEEE 1394 OHCI Controller
> >         Flags: medium devsel, IRQ 255
> >         Memory at fc800000 (32-bit, non-prefetchable) [disabled] [size=2K]
> >         I/O ports at d000 [disabled] [size=128]
> >         Capabilities: [50] Power Management version 2
> >         Kernel modules: firewire_ohci
> > 
> > There are currently no devices connected.
> > 
> > I could work around the issue by blacklisting the module, since I
> > currently don't use the FireWire hardware (but there are still some DV
> > tapes waiting to be transferred...)
> > 
> > Regards, Tobias
> 
> 
> Thanks
> 
> Takashi Sakamoto

Re: Hard crash when loading firewire-ohci

[Takashi S. <o-t...@sa...>]

Hi,

The change for 1394 OHCI driver, aimed at suppressing the unexpected
system reboot in AMD Ryzen machine[1], has been merged into Linux kernel
v6.7[2]. It has also been applied to the following releases of stable and
longterm kernels.

* 6.6.11[3]
* 6.1.72[4]
* 5.15.147[5]
* 5.10.208[6]
* 5.4.267[7]
* 4.19.305[8]
* 4.14.336[9]

Once the downstream distribution project provides the corresponding kernel
packages, you should no longer encounter the unexpected system reboot.

Note that the following combination of hardware is not necessarily suitable,
depending on your use case:

* Any type of AMD Ryzen machine
* 1394 OHCI hardware consists of:
    * Asmedia ASM1083/1085
    * VIA VT6306/6307/6308

When working with time-aware protocol, such as audio sample processing, it
is advisable to avoid the combination. The change accompanies a functional
limitation that the software stack does not provides precise hardware time
in this case.

If you choose to continue using AMD Ryzen machine, the recommendation is
to replace the 1394 OHCI hardware with another one. Conversely, if you
choose to continue using the 1394 OHCI hardware, the recommendation is to
use the machine provided by vendors other than AMD.

Thanks for your report and long patience.

[1] https://git.kernel.org/torvalds/linux/c/ac9184fbb847
[2] https://lore.kernel.org/lkml/CAHk-=wid...@ma.../
[3] https://lore.kernel.org/lkml/2024011058-sheep-thrower-d2f8@gregkh/
[4] https://lore.kernel.org/lkml/2024011052-unsightly-bronze-e628@gregkh/
[5] https://lore.kernel.org/lkml/2024011541-defective-scuff-c55e@gregkh/
[6] https://lore.kernel.org/lkml/2024011532-lustiness-hybrid-fc72@gregkh/
[7] https://lore.kernel.org/lkml/2024011519-mating-tag-1f62@gregkh/
[8] https://lore.kernel.org/lkml/2024011508-shakiness-resonant-f15e@gregkh/
[9] https://lore.kernel.org/lkml/2024011046-ecology-tiptoeing-ce50@gregkh/

On Tue, Dec 12, 2023 at 01:13:40AM +0100, Tobias Gruetzmacher wrote:
> [Resend because I wasn't subcribed before]
> 
> Hi,
> 
> in recent kernels (noticed with Debian kernel 6.5) I get a hard crash
> when the firewire-ohci module is loaded.
> 
> I could bisect this issue to commit
> 
> dcadfd7f7c74ef9ee415e072a19bdf6c085159eb is the first bad commit
> commit dcadfd7f7c74ef9ee415e072a19bdf6c085159eb
> Author: Takashi Sakamoto <o-t...@sa...>
> Date:   Tue May 30 08:12:40 2023 +0900
> 
>     firewire: core: use union for callback of transaction completion
> 
> But I'm not sure how to continue debugging from here, since I don't get
> any output after
> 
> [Dec10 19:17] firewire_ohci 0000:0b:00.0: enabling device (0000 -> 0003)
> [  +0.075791] firewire_ohci 0000:0b:00.0: added OHCI v1.0 device as card 0, 4 IR + 8 IT contexts, quirks 0x11
> 
> My hardware is:
> 
> 0b:00.0 FireWire (IEEE 1394): VIA Technologies, Inc. VT6306/7/8 [Fire II(M)] IEEE 1394 OHCI Controller (rev c0) (prog-if 10 [OHCI])
>         Subsystem: VIA Technologies, Inc. VT6306/7/8 [Fire II(M)] IEEE 1394 OHCI Controller
>         Flags: medium devsel, IRQ 255
>         Memory at fc800000 (32-bit, non-prefetchable) [disabled] [size=2K]
>         I/O ports at d000 [disabled] [size=128]
>         Capabilities: [50] Power Management version 2
>         Kernel modules: firewire_ohci
> 
> There are currently no devices connected.
> 
> I could work around the issue by blacklisting the module, since I
> currently don't use the FireWire hardware (but there are still some DV
> tapes waiting to be transferred...)
> 
> Regards, Tobias


Thanks

Takashi Sakamoto