Re: [PATCH] firewire: core: option to log bus reset initiation

Re: [PATCH] firewire: core: option to log bus reset initiation

[Takashi Sakamoto]

Hi Adam,

On Wed, Mar 20, 2024 at 02:14:11AM -0700, Adam Goldman wrote:
> Add a debug parameter to firewire-core, analogous to the one in 
> firewire-ohci. When this is set to 1, log when we schedule, delay, or 
> initiate a bus reset. Since FireWire bus resets can originate from any 
> node on the bus, specific logging of the resets we initiate provides 
> additional insight.
> 
> Signed-off-by: Adam Goldman <adamg@pobox.com>

Thanks for the patch. I applied it to for-next[1].

Now we have two debug parameters per module for the slightly-similar
purpose. In my opinion, it is a pretty cumbersome to enable them when
checking bus-reset behaviour. I think it is time to investigate the other
way.

Linux Kernel Tracepoints[2] is one of options. Roughly describing, the
tracepoints mechanism allows users to deliver structured data from kernel
space to user space via ring-buffer when enabling it by either sysfs or
kernel command-line parameters. Linux kernel also has a command-line
parameter to redirect the human-readable formatted data to kernel log[3].
I think it is suitable in the case.

It requires many work to replace the existent debug parameter of
firewire-ohci, while it is a good start to work just for bus-reset debug.
The data structure layout should be pre-defined in each subsystem, thus we
need to decide it. In my opinion, it would be like:

```
struct bus_reset_event {
    enum reason {
        Initiate,
	Schedule,
	Postpone,
	Detect,
    },
    // We can put any other data if prefering.
}
```

Would I ask your opinion about my idea?


[1] https://git.kernel.org/pub/scm/linux/kernel/git/ieee1394/linux1394.git/log/?h=for-next
[2] https://docs.kernel.org/trace/tracepoints.html
[3] 'tp_printk' in kernel/trace/trace.c, 'trace_event' in kernel/trace/trace_event.c

Regards

Takashi Sakamoto

Re: [PATCH] firewire: core: option to log bus reset initiation

[Adam Goldman]

Hi Takashi,

On Mon, Mar 25, 2024 at 09:41:34AM +0900, Takashi Sakamoto wrote:
> Now we have two debug parameters per module for the slightly-similar
> purpose. In my opinion, it is a pretty cumbersome to enable them when
> checking bus-reset behaviour. I think it is time to investigate the other
> way.
> 
> Linux Kernel Tracepoints[2] is one of options. Roughly describing, the
> tracepoints mechanism allows users to deliver structured data from kernel
> space to user space via ring-buffer when enabling it by either sysfs or
> kernel command-line parameters. Linux kernel also has a command-line
> parameter to redirect the human-readable formatted data to kernel log[3].
> I think it is suitable in the case.
> 
> It requires many work to replace the existent debug parameter of
> firewire-ohci, while it is a good start to work just for bus-reset debug.
> The data structure layout should be pre-defined in each subsystem, thus we
> need to decide it. In my opinion, it would be like:
> 
> ```
> struct bus_reset_event {
>     enum reason {
>         Initiate,
> 	Schedule,
> 	Postpone,
> 	Detect,
>     },
>     // We can put any other data if prefering.
> }
> ```

Maybe these should be four separate trace events?

> Would I ask your opinion about my idea?

It seems that tracepoints are the modern way to make debugging logs, so 
if we want to modernize the FireWire driver, we should replace the 
existent logging with tracepoints.

-- Adam

Re: [PATCH] firewire: core: option to log bus reset initiation

[Takashi Sakamoto]

Hi,

On Tue, Mar 26, 2024 at 05:18:32AM -0700, Adam Goldman wrote:
> Hi Takashi,
> 
> On Mon, Mar 25, 2024 at 09:41:34AM +0900, Takashi Sakamoto wrote:
> > Now we have two debug parameters per module for the slightly-similar
> > purpose. In my opinion, it is a pretty cumbersome to enable them when
> > checking bus-reset behaviour. I think it is time to investigate the other
> > way.
> > 
> > Linux Kernel Tracepoints[2] is one of options. Roughly describing, the
> > tracepoints mechanism allows users to deliver structured data from kernel
> > space to user space via ring-buffer when enabling it by either sysfs or
> > kernel command-line parameters. Linux kernel also has a command-line
> > parameter to redirect the human-readable formatted data to kernel log[3].
> > I think it is suitable in the case.
> > 
> > It requires many work to replace the existent debug parameter of
> > firewire-ohci, while it is a good start to work just for bus-reset debug.
> > The data structure layout should be pre-defined in each subsystem, thus we
> > need to decide it. In my opinion, it would be like:
> > 
> > ```
> > struct bus_reset_event {
> >     enum reason {
> >         Initiate,
> > 	Schedule,
> > 	Postpone,
> > 	Detect,
> >     },
> >     // We can put any other data if prefering.
> > }
> > ```
> 
> Maybe these should be four separate trace events?
> 
> > Would I ask your opinion about my idea?
> 
> It seems that tracepoints are the modern way to make debugging logs, so 
> if we want to modernize the FireWire driver, we should replace the 
> existent logging with tracepoints.

Thanks for your positive comment.

I pushed my work-in-progress patches to the following specific topic
branch::
https://github.com/takaswie/linux-firewire-dkms/tree/topic/backport-to-v6.8/tracepoints

You can see some patches onto your commits:

* 145da78e firewire: ohci: obsolete OHCI_PARAM_DEBUG_BUSRESETS from debug parameter with tracepoints event
* 3bdad35d firewire: core: obsolete debug parameter with tracepoints event
* 30f489af firewire: ohci: support bus_reset tracepoints event
* 4937d9c8 firewire: core: support bus_reset tracepoints event
* 0da26087 firewire: core: add support for Linux kernel tracepoints
* 961cba18 firewire: core: option to log bus reset initiation
* b3124560 firewire: ohci: mask bus reset interrupts between ISR and bottom half

In the above, I added 'bus_reset' events in 'firewire' tracepoints
subsystem. The structure is something like:

```
struct bus_reset {
    enum fw_trace_bus_reset_issue issue;
    bool short_reset;
};
```

The issue enumerations are in 'drivers/firewire/core.h':

```
enum fw_trace_bus_reset_issue {
	FW_TRACE_BUS_RESET_ISSUE_INITIATE = 0,
	FW_TRACE_BUS_RESET_ISSUE_SCHEDULE,
	FW_TRACE_BUS_RESET_ISSUE_POSTPONE,
	FW_TRACE_BUS_RESET_ISSUE_DETECT,
};
```

You can see the above event is trigerred by two kernel modules:

* firewire-core
* firewire-ohci

When merging the above changes and build/load the kernel modules, we can
see 'firewire:bus_reset' event in Linux Kernel tracepoints system, like:

```
$ ls /sys/kernel/debug/tracing/events/firewire/bus_reset
```

I currently consider about a pair of events for OHCI interrupts and PHY
operation, instead of the above event. I'm happy if receiving your
opinion about it or the other ideas.


Regards

Takashi Sakamoto