Thread: [PATCH] firewire: core: option to log bus reset initiation
Brought to you by:
aeb,
bencollins
From: Adam G. <ad...@po...> - 2024-03-20 09:14:31
|
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 <ad...@po...> --- --- linux-6.8-rc1.orig/drivers/firewire/core.h 2024-01-21 14:11:32.000000000 -0800 +++ linux-6.8-rc1/drivers/firewire/core.h 2024-03-10 03:56:09.000000000 -0700 @@ -238,6 +238,10 @@ /* OHCI-1394's default upper bound for physical DMA: 4 GB */ #define FW_MAX_PHYSICAL_RANGE (1ULL << 32) +#define FW_CORE_PARAM_DEBUG_BUSRESETS 1 + +extern int fw_core_param_debug; + void fw_core_handle_request(struct fw_card *card, struct fw_packet *request); void fw_core_handle_response(struct fw_card *card, struct fw_packet *packet); int fw_get_response_length(struct fw_request *request); --- linux-6.8-rc1.orig/drivers/firewire/core-transaction.c 2024-01-21 14:11:32.000000000 -0800 +++ linux-6.8-rc1/drivers/firewire/core-transaction.c 2024-03-12 02:08:29.000000000 -0700 @@ -1385,5 +1385,12 @@ idr_destroy(&fw_device_idr); } +int fw_core_param_debug; +module_param_named(debug, fw_core_param_debug, int, 0644); +MODULE_PARM_DESC(debug, "Verbose logging (default = 0" + ", bus resets = " __stringify(FW_CORE_PARAM_DEBUG_BUSRESETS) + ")"); + + module_init(fw_core_init); module_exit(fw_core_cleanup); --- linux-6.8-rc1.orig/drivers/firewire/core-card.c 2024-01-21 14:11:32.000000000 -0800 +++ linux-6.8-rc1/drivers/firewire/core-card.c 2024-03-10 03:34:00.000000000 -0700 @@ -221,11 +221,19 @@ int reg = short_reset ? 5 : 1; int bit = short_reset ? PHY_BUS_SHORT_RESET : PHY_BUS_RESET; + if (unlikely(fw_core_param_debug & FW_CORE_PARAM_DEBUG_BUSRESETS)) + fw_notice(card, "initiating %s bus reset\n", + short_reset ? "short" : "long"); + return card->driver->update_phy_reg(card, reg, 0, bit); } void fw_schedule_bus_reset(struct fw_card *card, bool delayed, bool short_reset) { + if (unlikely(fw_core_param_debug & FW_CORE_PARAM_DEBUG_BUSRESETS)) + fw_notice(card, "scheduling %s bus reset\n", + short_reset ? "short" : "long"); + /* We don't try hard to sort out requests of long vs. short resets. */ card->br_short = short_reset; @@ -244,6 +252,8 @@ /* Delay for 2s after last reset per IEEE 1394 clause 8.2.1. */ if (card->reset_jiffies != 0 && time_before64(get_jiffies_64(), card->reset_jiffies + 2 * HZ)) { + if (unlikely(fw_core_param_debug & FW_CORE_PARAM_DEBUG_BUSRESETS)) + fw_notice(card, "delaying bus reset\n"); if (!queue_delayed_work(fw_workqueue, &card->br_work, 2 * HZ)) fw_card_put(card); return; |
From: Takashi S. <o-t...@sa...> - 2024-03-25 00:41:47
|
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 <ad...@po...> 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 |
From: Adam G. <ad...@po...> - 2024-03-26 12:18:56
|
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 |
From: Takashi S. <o-t...@sa...> - 2024-03-26 12:39:09
|
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 |