On Mon, Apr 27, 2009 at 09:07:33PM -0700, David Brownell wrote:
> An interesting pair of patches ... but this one shows, I think,
> that it needs a bit of cleanup yet. Way too much #ifdeffery.
>
>
> On Monday 27 April 2009, Sarah Sharp wrote:
> > This patch adds hardware throughput statistics to EHCI. These statistics report
> > the MBps for each URB submitted to the driver. This attempts to measure the
> > delta time between when the buffers in the URB are submitted to the hardware and
> > when the hardware completes all the qTDs or iTDs for that URB.
> >
> > The timing information is stashed in the struct urb. The EHCI driver updates
> > the statistics reported by the "tp-stat" file in debugfs/ehci/.
> >
> > This patch is not completely correct. I see negative time deltas on the first
> > of several 4096 byte transfers. That means the code is probably not setting a
> > start time in some path from ehci_urb_enqueue().
>
> And a bug. ;)
Yes, I was hoping you could help me find the bug, since I don't
understand the EHCI urb enqueue path as well as you.
> I'm a bit curious why you wouldn't add all this statistics code
> to usbcore, instead of modifying each HCD. You've already got
> single access points for submit and giveback paths; and doing it
> in usbcore would provide much more consistent measurements.
I wanted a way to measure the hardware performance, minus any software
overhead for giving back the URBs, drivers resubmitting, etc. I wanted
the finished timestamp for the URB to be as close as possible to the
time of the hardware interrupt, so there had to be unique code for each
HCD. I also wanted to make it generic enough that you could measure the
overhead of different parts of the USB software stack.
Thanks for your comments about the ifdef'ness. I'll respin this.
> > Signed-off-by: Sarah Sharp <sarah.a.sharp@xxxxxxxxxxxxxxx>
> > ---
> > drivers/usb/host/ehci-dbg.c | 7 +++++++
> > drivers/usb/host/ehci-hcd.c | 16 ++++++++++++++++
> > drivers/usb/host/ehci-q.c | 18 ++++++++++++++++++
> > drivers/usb/host/ehci-sched.c | 12 ++++++++++++
> > include/linux/usb.h | 4 ++++
> > 5 files changed, 57 insertions(+), 0 deletions(-)
> >
> > diff --git a/drivers/usb/host/ehci-dbg.c b/drivers/usb/host/ehci-dbg.c
> > index 7f4ace7..88c3b95 100644
> > --- a/drivers/usb/host/ehci-dbg.c
> > +++ b/drivers/usb/host/ehci-dbg.c
> > @@ -18,6 +18,10 @@
> >
> > /* this file is part of ehci-hcd.c */
> >
> > +#ifdef CONFIG_USB_HCD_STAT
> > +#include "hcd-dbg.h"
> > +#endif
>
> No reason to #ifdef this, is there?
>
>
> > +
> > #define ehci_dbg(ehci, fmt, args...) \
> > dev_dbg (ehci_to_hcd(ehci)->self.controller , fmt , ## args )
> > #define ehci_err(ehci, fmt, args...) \
> > @@ -352,6 +356,9 @@ static const struct file_operations debug_registers_fops = {
> > };
> >
> > static struct dentry *ehci_debug_root;
> > +#ifdef CONFIG_USB_HCD_STAT
> > +static struct hcd_stat *ehci_debug_stats;
> > +#endif
>
> Hmm, shouldn't that be per-HCD? And again, not #ifdeffed.
>
>
> >
> > struct debug_buffer {
> > ssize_t (*fill_func)(struct debug_buffer *); /* fill method */
> > diff --git a/drivers/usb/host/ehci-hcd.c b/drivers/usb/host/ehci-hcd.c
> > index c637207..d77fd9a 100644
> > --- a/drivers/usb/host/ehci-hcd.c
> > +++ b/drivers/usb/host/ehci-hcd.c
> > @@ -1102,6 +1102,15 @@ static int __init ehci_hcd_init(void)
> > retval = -ENOENT;
> > goto err_debug;
> > }
> > +#ifdef CONFIG_USB_HCD_STAT
> > + ehci_debug_stats = hcd_stat_alloc(ehci_debug_root,
> > + "tp-stats", GFP_KERNEL);
> > + if (!ehci_debug_stats) {
> > + debugfs_remove(ehci_debug_root);
> > + retval = -ENOENT;
> > + goto err_debug;
> > + }
> > +#endif
>
> The #ifdeffery there would normally be along the lines of
> having an hcd_stat_alloc() version that's inlined to return
> NULL when not debugging, and using IS_ERR() to check for
> valid outcomes otherwise.
>
>
> > #endif
> >
> > #ifdef PLATFORM_DRIVER
> > @@ -1147,6 +1156,10 @@ clean0:
> > #endif
> > #ifdef DEBUG
> > debugfs_remove(ehci_debug_root);
> > +#ifdef CONFIG_USB_HCD_STAT
> > + hcd_stat_free(ehci_debug_stats);
> > + ehci_debug_stats = NULL;
>
> Likewise hcd_stat_free() would have an inlined NOP implementation
> when not using this infrastructure.
>
>
> > +#endif
> > ehci_debug_root = NULL;
> > err_debug:
> > #endif
> > @@ -1170,6 +1183,9 @@ static void __exit ehci_hcd_cleanup(void)
> > ps3_ehci_driver_unregister(&PS3_SYSTEM_BUS_DRIVER);
> > #endif
> > #ifdef DEBUG
> > +#ifdef CONFIG_USB_HCD_STAT
> > + hcd_stat_free(ehci_debug_stats);
> > +#endif
> > debugfs_remove(ehci_debug_root);
> > #endif
> > clear_bit(USB_EHCI_LOADED, &usb_hcds_loaded);
> > diff --git a/drivers/usb/host/ehci-q.c b/drivers/usb/host/ehci-q.c
> > index 1976b1b..6302615 100644
> > --- a/drivers/usb/host/ehci-q.c
> > +++ b/drivers/usb/host/ehci-q.c
> > @@ -247,6 +247,12 @@ __acquires(ehci->lock)
> > status = 0;
> > COUNT(ehci->stats.complete);
> > }
> > +#ifdef DEBUG
> > +#ifdef CONFIG_USB_HCD_STAT
> > + hcd_stat_update(ehci_debug_stats, urb->actual_length,
> > + ktime_sub(urb->time_completed, urb->time_submitted));
>
> Ditto a NOP inline for this function, when not using this ...
>
>
> > +#endif
> > +#endif
> >
> > #ifdef EHCI_URB_TRACE
> > ehci_dbg (ehci,
> > @@ -286,6 +292,9 @@ qh_completions (struct ehci_hcd *ehci, struct ehci_qh *qh)
> > unsigned count = 0;
> > u8 state;
> > __le32 halt = HALT_BIT(ehci);
> > +#ifdef CONFIG_USB_HCD_STAT
> > + ktime_t irq_time = ktime_get();
>
> ... likewise here, but you'd also define a new function
> (because ktime_get must always work).
>
>
> > +#endif
> >
> > if (unlikely (list_empty (&qh->qtd_list)))
> > return count;
> > @@ -316,6 +325,9 @@ qh_completions (struct ehci_hcd *ehci, struct ehci_qh *qh)
> > /* clean up any state from previous QTD ...*/
> > if (last) {
> > if (likely (last->urb != urb)) {
> > +#ifdef CONFIG_USB_HCD_STAT
> > + urb->time_completed = irq_time;
>
> You might either always provide time_completed, or
> conditionally provide get/set accessors (which turn
> into NOPs when hcd stats aren't provided).
>
>
> > +#endif
> > ehci_urb_done(ehci, last->urb, last_status);
> > count++;
> > last_status = -EINPROGRESS;
> > @@ -456,6 +468,9 @@ halt:
> >
> > /* last urb's completion might still need calling */
> > if (likely (last != NULL)) {
> > +#ifdef CONFIG_USB_HCD_STAT
> > + last->urb->time_completed = irq_time;
> > +#endif
> > ehci_urb_done(ehci, last->urb, last_status);
> > count++;
> > ehci_qtd_free (ehci, last);
> > @@ -977,6 +992,9 @@ static struct ehci_qh *qh_append_tds (
> >
> > /* let the hc process these next qtds */
> > wmb ();
> > +#ifdef CONFIG_USB_HCD_STAT
> > + urb->time_submitted = ktime_get();
> > +#endif
> > dummy->hw_token = token;
> >
> > urb->hcpriv = qh_get (qh);
> > diff --git a/drivers/usb/host/ehci-sched.c b/drivers/usb/host/ehci-sched.c
> > index 556d0ec..87c6ca5 100644
> > --- a/drivers/usb/host/ehci-sched.c
> > +++ b/drivers/usb/host/ehci-sched.c
> > @@ -1557,6 +1557,9 @@ itd_link_urb (
> > itd = NULL;
> > }
> > }
> > +#ifdef CONFIG_USB_HCD_STAT
> > + urb->time_submitted = ktime_get();
> > +#endif
> > stream->next_uframe = next_uframe;
> >
> > /* don't need that schedule data any more */
> > @@ -2133,6 +2136,9 @@ scan_periodic (struct ehci_hcd *ehci)
> > {
> > unsigned now_uframe, frame, clock, clock_frame, mod;
> > unsigned modified;
> > +#ifdef CONFIG_USB_HCD_STAT
> > + ktime_t irq_time = ktime_get();
> > +#endif
> >
> > mod = ehci->periodic_size << 3;
> >
> > @@ -2231,6 +2237,9 @@ restart:
> > *hw_p = q.itd->hw_next;
> > type = Q_NEXT_TYPE(ehci, q.itd->hw_next);
> > wmb();
> > +#ifdef CONFIG_USB_HCD_STAT
> > + q.itd->urb->time_completed = irq_time;
> > +#endif
> > modified = itd_complete (ehci, q.itd);
> > q = *q_p;
> > break;
> > @@ -2260,6 +2269,9 @@ restart:
> > *hw_p = q.sitd->hw_next;
> > type = Q_NEXT_TYPE(ehci, q.sitd->hw_next);
> > wmb();
> > +#ifdef CONFIG_USB_HCD_STAT
> > + q.sitd->urb->time_completed = irq_time;
> > +#endif
> > modified = sitd_complete (ehci, q.sitd);
> > q = *q_p;
> > break;
> > diff --git a/include/linux/usb.h b/include/linux/usb.h
> > index 3aa2cd1..1114038 100644
> > --- a/include/linux/usb.h
> > +++ b/include/linux/usb.h
> > @@ -1164,6 +1164,10 @@ struct urb {
> > atomic_t use_count; /* concurrent submissions counter */
> > atomic_t reject; /* submissions will fail */
> > int unlinked; /* unlink error code */
> > +#ifdef CONFIG_USB_HCD_STAT
> > + ktime_t time_submitted;
> > + ktime_t time_completed;
>
> This should be part of the first patch (providing infrastructure
> for HCDs to use).
I included thsi in the EHCI patch because the xHCI driver keeps track of
the time stamp in an internal data structure, and doesn't need these
fields. I would have used an internal EHCI structure, if I had had time
to stare at the code more.
> > +#endif
> >
> > /* public: documented fields in the urb that can be used by drivers */
> > struct list_head urb_list; /* list head for use by the urb's
> > --
> > 1.5.6.5
> >
> > --
> > To unsubscribe from this list: send the line "unsubscribe linux-usb" in
> > the body of a message to majordomo@xxxxxxxxxxxxxxx
> > More majordomo info at http://vger.kernel.org/majordomo-info.html
> >
> >
>
>
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
