[v2] usb: dwc2: host: use hrtimer for NAK retries
diff mbox series

Message ID 153655347149.19910.4781444209586693527.stgit@Rincon.localdomain
State New
Headers show
Series
  • [v2] usb: dwc2: host: use hrtimer for NAK retries
Related show

Commit Message

Terin Stock Sept. 10, 2018, 4:24 a.m. UTC
Modify the wait delay utilize the high resolution timer API to allow for
more precisely scheduled callbacks.

A previous commit added a 1ms retry delay after multiple consecutive
NAKed transactions using jiffies. On systems with a low timer interrupt
frequency, this delay may be significantly longer than specified,
resulting in misbehavior with some USB devices.

This scenario was reached on a Raspberry Pi 3B with a Macally FDD-USB
floppy drive (identified as 0424:0fdc Standard Microsystems Corp.
Floppy, based on the USB97CFDC USB FDC). With the relay delay, the drive
would be unable to mount a disk, replying with NAKs until the device was
reset.

Using ktime, the delta between starting the timer (in dwc2_hcd_qh_add)
and the callback function can be determined. With the original delay
implementation, this value was consistently approximately 12ms. (output
in us).

    <idle>-0     [000] ..s.  1600.559974: dwc2_wait_timer_fn: wait_timer delta: 11976
    <idle>-0     [000] ..s.  1600.571974: dwc2_wait_timer_fn: wait_timer delta: 11977
    <idle>-0     [000] ..s.  1600.583974: dwc2_wait_timer_fn: wait_timer delta: 11976
    <idle>-0     [000] ..s.  1600.595974: dwc2_wait_timer_fn: wait_timer delta: 11977

After converting the relay delay to using a higher resolution timer, the
delay was much closer to 1ms.

    <idle>-0     [000] d.h.  1956.553017: dwc2_wait_timer_fn: wait_timer delta: 1002
    <idle>-0     [000] d.h.  1956.554114: dwc2_wait_timer_fn: wait_timer delta: 1002
    <idle>-0     [000] d.h.  1957.542660: dwc2_wait_timer_fn: wait_timer delta: 1004
    <idle>-0     [000] d.h.  1957.543701: dwc2_wait_timer_fn: wait_timer delta: 1002

The floppy drive operates properly with delays up to approximately 5ms,
and sends NAKs for any delays that are longer.

Fixes: 38d2b5fb75c1 ("usb: dwc2: host: Don't retry NAKed transactions right away")
Signed-off-by: Terin Stock <terin@terinstock.com>
---
 drivers/usb/dwc2/hcd.h       |    2 +-
 drivers/usb/dwc2/hcd_queue.c |   19 ++++++++++++-------
 2 files changed, 13 insertions(+), 8 deletions(-)

Comments

Doug Anderson Nov. 13, 2018, 11:30 p.m. UTC | #1
Hi,

On Sun, Sep 9, 2018 at 9:24 PM Terin Stock <terin@terinstock.com> wrote:
>
> Modify the wait delay utilize the high resolution timer API to allow for
> more precisely scheduled callbacks.
>
> A previous commit added a 1ms retry delay after multiple consecutive
> NAKed transactions using jiffies. On systems with a low timer interrupt
> frequency, this delay may be significantly longer than specified,
> resulting in misbehavior with some USB devices.
>
> This scenario was reached on a Raspberry Pi 3B with a Macally FDD-USB
> floppy drive (identified as 0424:0fdc Standard Microsystems Corp.
> Floppy, based on the USB97CFDC USB FDC). With the relay delay, the drive
> would be unable to mount a disk, replying with NAKs until the device was
> reset.
>
> Using ktime, the delta between starting the timer (in dwc2_hcd_qh_add)
> and the callback function can be determined. With the original delay
> implementation, this value was consistently approximately 12ms. (output
> in us).
>
>     <idle>-0     [000] ..s.  1600.559974: dwc2_wait_timer_fn: wait_timer delta: 11976
>     <idle>-0     [000] ..s.  1600.571974: dwc2_wait_timer_fn: wait_timer delta: 11977
>     <idle>-0     [000] ..s.  1600.583974: dwc2_wait_timer_fn: wait_timer delta: 11976
>     <idle>-0     [000] ..s.  1600.595974: dwc2_wait_timer_fn: wait_timer delta: 11977
>
> After converting the relay delay to using a higher resolution timer, the
> delay was much closer to 1ms.
>
>     <idle>-0     [000] d.h.  1956.553017: dwc2_wait_timer_fn: wait_timer delta: 1002
>     <idle>-0     [000] d.h.  1956.554114: dwc2_wait_timer_fn: wait_timer delta: 1002
>     <idle>-0     [000] d.h.  1957.542660: dwc2_wait_timer_fn: wait_timer delta: 1004
>     <idle>-0     [000] d.h.  1957.543701: dwc2_wait_timer_fn: wait_timer delta: 1002
>
> The floppy drive operates properly with delays up to approximately 5ms,
> and sends NAKs for any delays that are longer.
>
> Fixes: 38d2b5fb75c1 ("usb: dwc2: host: Don't retry NAKed transactions right away")
> Signed-off-by: Terin Stock <terin@terinstock.com>
> ---
>  drivers/usb/dwc2/hcd.h       |    2 +-
>  drivers/usb/dwc2/hcd_queue.c |   19 ++++++++++++-------
>  2 files changed, 13 insertions(+), 8 deletions(-)

Reviewed-by: Douglas Anderson <dianders@chromium.org>
Cc: stable@vger.kernel.org
Minas Harutyunyan Nov. 21, 2018, 7:16 a.m. UTC | #2
On 11/14/2018 3:30 AM, Doug Anderson wrote:
> Hi,
> 
> On Sun, Sep 9, 2018 at 9:24 PM Terin Stock <terin@terinstock.com> wrote:
>>
>> Modify the wait delay utilize the high resolution timer API to allow for
>> more precisely scheduled callbacks.
>>
>> A previous commit added a 1ms retry delay after multiple consecutive
>> NAKed transactions using jiffies. On systems with a low timer interrupt
>> frequency, this delay may be significantly longer than specified,
>> resulting in misbehavior with some USB devices.
>>
>> This scenario was reached on a Raspberry Pi 3B with a Macally FDD-USB
>> floppy drive (identified as 0424:0fdc Standard Microsystems Corp.
>> Floppy, based on the USB97CFDC USB FDC). With the relay delay, the drive
>> would be unable to mount a disk, replying with NAKs until the device was
>> reset.
>>
>> Using ktime, the delta between starting the timer (in dwc2_hcd_qh_add)
>> and the callback function can be determined. With the original delay
>> implementation, this value was consistently approximately 12ms. (output
>> in us).
>>
>>      <idle>-0     [000] ..s.  1600.559974: dwc2_wait_timer_fn: wait_timer delta: 11976
>>      <idle>-0     [000] ..s.  1600.571974: dwc2_wait_timer_fn: wait_timer delta: 11977
>>      <idle>-0     [000] ..s.  1600.583974: dwc2_wait_timer_fn: wait_timer delta: 11976
>>      <idle>-0     [000] ..s.  1600.595974: dwc2_wait_timer_fn: wait_timer delta: 11977
>>
>> After converting the relay delay to using a higher resolution timer, the
>> delay was much closer to 1ms.
>>
>>      <idle>-0     [000] d.h.  1956.553017: dwc2_wait_timer_fn: wait_timer delta: 1002
>>      <idle>-0     [000] d.h.  1956.554114: dwc2_wait_timer_fn: wait_timer delta: 1002
>>      <idle>-0     [000] d.h.  1957.542660: dwc2_wait_timer_fn: wait_timer delta: 1004
>>      <idle>-0     [000] d.h.  1957.543701: dwc2_wait_timer_fn: wait_timer delta: 1002
>>
>> The floppy drive operates properly with delays up to approximately 5ms,
>> and sends NAKs for any delays that are longer.
>>
>> Fixes: 38d2b5fb75c1 ("usb: dwc2: host: Don't retry NAKed transactions right away")
>> Signed-off-by: Terin Stock <terin@terinstock.com>
>> ---
>>   drivers/usb/dwc2/hcd.h       |    2 +-
>>   drivers/usb/dwc2/hcd_queue.c |   19 ++++++++++++-------
>>   2 files changed, 13 insertions(+), 8 deletions(-)
> 
> Reviewed-by: Douglas Anderson <dianders@chromium.org>
> Cc: stable@vger.kernel.org
> 
Acked-by: Minas Harutyunyan <hminas@synopsys.com>
Doug Anderson Nov. 21, 2018, 4:11 p.m. UTC | #3
Felipe,

On Tue, Nov 20, 2018 at 11:16 PM Minas Harutyunyan
<minas.harutyunyan@synopsys.com> wrote:
>
> On 11/14/2018 3:30 AM, Doug Anderson wrote:
> > Hi,
> >
> > On Sun, Sep 9, 2018 at 9:24 PM Terin Stock <terin@terinstock.com> wrote:
> >>
> >> Modify the wait delay utilize the high resolution timer API to allow for
> >> more precisely scheduled callbacks.
> >>
> >> A previous commit added a 1ms retry delay after multiple consecutive
> >> NAKed transactions using jiffies. On systems with a low timer interrupt
> >> frequency, this delay may be significantly longer than specified,
> >> resulting in misbehavior with some USB devices.
> >>
> >> This scenario was reached on a Raspberry Pi 3B with a Macally FDD-USB
> >> floppy drive (identified as 0424:0fdc Standard Microsystems Corp.
> >> Floppy, based on the USB97CFDC USB FDC). With the relay delay, the drive
> >> would be unable to mount a disk, replying with NAKs until the device was
> >> reset.
> >>
> >> Using ktime, the delta between starting the timer (in dwc2_hcd_qh_add)
> >> and the callback function can be determined. With the original delay
> >> implementation, this value was consistently approximately 12ms. (output
> >> in us).
> >>
> >>      <idle>-0     [000] ..s.  1600.559974: dwc2_wait_timer_fn: wait_timer delta: 11976
> >>      <idle>-0     [000] ..s.  1600.571974: dwc2_wait_timer_fn: wait_timer delta: 11977
> >>      <idle>-0     [000] ..s.  1600.583974: dwc2_wait_timer_fn: wait_timer delta: 11976
> >>      <idle>-0     [000] ..s.  1600.595974: dwc2_wait_timer_fn: wait_timer delta: 11977
> >>
> >> After converting the relay delay to using a higher resolution timer, the
> >> delay was much closer to 1ms.
> >>
> >>      <idle>-0     [000] d.h.  1956.553017: dwc2_wait_timer_fn: wait_timer delta: 1002
> >>      <idle>-0     [000] d.h.  1956.554114: dwc2_wait_timer_fn: wait_timer delta: 1002
> >>      <idle>-0     [000] d.h.  1957.542660: dwc2_wait_timer_fn: wait_timer delta: 1004
> >>      <idle>-0     [000] d.h.  1957.543701: dwc2_wait_timer_fn: wait_timer delta: 1002
> >>
> >> The floppy drive operates properly with delays up to approximately 5ms,
> >> and sends NAKs for any delays that are longer.
> >>
> >> Fixes: 38d2b5fb75c1 ("usb: dwc2: host: Don't retry NAKed transactions right away")
> >> Signed-off-by: Terin Stock <terin@terinstock.com>
> >> ---
> >>   drivers/usb/dwc2/hcd.h       |    2 +-
> >>   drivers/usb/dwc2/hcd_queue.c |   19 ++++++++++++-------
> >>   2 files changed, 13 insertions(+), 8 deletions(-)
> >
> > Reviewed-by: Douglas Anderson <dianders@chromium.org>
> > Cc: stable@vger.kernel.org
> >
> Acked-by: Minas Harutyunyan <hminas@synopsys.com>

It looks like Terin missed CCing you on the original patch.  I assume
you are still picking up dwc2 changes like this?  If so, should he
resend the patch targeting you (and including Minas and my tags) or do
you want to pick it up from one of the mailing lists he CCed?

Thanks!

-Doug
Felipe Balbi Dec. 5, 2018, 9:13 a.m. UTC | #4
Hi,

Doug Anderson <dianders@chromium.org> writes:
> >> Signed-off-by: Terin Stock <terin@terinstock.com>
>> >> ---
>> >>   drivers/usb/dwc2/hcd.h       |    2 +-
>> >>   drivers/usb/dwc2/hcd_queue.c |   19 ++++++++++++-------
>> >>   2 files changed, 13 insertions(+), 8 deletions(-)
>> >
>> > Reviewed-by: Douglas Anderson <dianders@chromium.org>
>> > Cc: stable@vger.kernel.org
>> >
>> Acked-by: Minas Harutyunyan <hminas@synopsys.com>
>
> It looks like Terin missed CCing you on the original patch.  I assume
> you are still picking up dwc2 changes like this?  If so, should he
> resend the patch targeting you (and including Minas and my tags) or do
> you want to pick it up from one of the mailing lists he CCed?

I'm picking it up, thanks

Patch
diff mbox series

diff --git a/drivers/usb/dwc2/hcd.h b/drivers/usb/dwc2/hcd.h
index 5502a501f516..93483dc37801 100644
--- a/drivers/usb/dwc2/hcd.h
+++ b/drivers/usb/dwc2/hcd.h
@@ -366,7 +366,7 @@  struct dwc2_qh {
 	u32 desc_list_sz;
 	u32 *n_bytes;
 	struct timer_list unreserve_timer;
-	struct timer_list wait_timer;
+	struct hrtimer wait_timer;
 	struct dwc2_tt *dwc_tt;
 	int ttport;
 	unsigned tt_buffer_dirty:1;
diff --git a/drivers/usb/dwc2/hcd_queue.c b/drivers/usb/dwc2/hcd_queue.c
index 301ced1618f8..60caf8e0b762 100644
--- a/drivers/usb/dwc2/hcd_queue.c
+++ b/drivers/usb/dwc2/hcd_queue.c
@@ -59,7 +59,7 @@ 
 #define DWC2_UNRESERVE_DELAY (msecs_to_jiffies(5))
 
 /* If we get a NAK, wait this long before retrying */
-#define DWC2_RETRY_WAIT_DELAY (msecs_to_jiffies(1))
+#define DWC2_RETRY_WAIT_DELAY 1*1E6L
 
 /**
  * dwc2_periodic_channel_available() - Checks that a channel is available for a
@@ -1464,10 +1464,12 @@  static void dwc2_deschedule_periodic(struct dwc2_hsotg *hsotg,
  * qh back to the "inactive" list, then queues transactions.
  *
  * @t: Pointer to wait_timer in a qh.
+ *
+ * Return: HRTIMER_NORESTART to not automatically restart this timer.
  */
-static void dwc2_wait_timer_fn(struct timer_list *t)
+static enum hrtimer_restart dwc2_wait_timer_fn(struct hrtimer *t)
 {
-	struct dwc2_qh *qh = from_timer(qh, t, wait_timer);
+	struct dwc2_qh *qh = container_of(t, struct dwc2_qh, wait_timer);
 	struct dwc2_hsotg *hsotg = qh->hsotg;
 	unsigned long flags;
 
@@ -1491,6 +1493,7 @@  static void dwc2_wait_timer_fn(struct timer_list *t)
 	}
 
 	spin_unlock_irqrestore(&hsotg->lock, flags);
+	return HRTIMER_NORESTART;
 }
 
 /**
@@ -1521,7 +1524,8 @@  static void dwc2_qh_init(struct dwc2_hsotg *hsotg, struct dwc2_qh *qh,
 	/* Initialize QH */
 	qh->hsotg = hsotg;
 	timer_setup(&qh->unreserve_timer, dwc2_unreserve_timer_fn, 0);
-	timer_setup(&qh->wait_timer, dwc2_wait_timer_fn, 0);
+	hrtimer_init(&qh->wait_timer, CLOCK_MONOTONIC, HRTIMER_MODE_REL);
+	qh->wait_timer.function = &dwc2_wait_timer_fn;
 	qh->ep_type = ep_type;
 	qh->ep_is_in = ep_is_in;
 
@@ -1690,7 +1694,7 @@  void dwc2_hcd_qh_free(struct dwc2_hsotg *hsotg, struct dwc2_qh *qh)
 	 * won't do anything anyway, but we want it to finish before we free
 	 * memory.
 	 */
-	del_timer_sync(&qh->wait_timer);
+	hrtimer_cancel(&qh->wait_timer);
 
 	dwc2_host_put_tt_info(hsotg, qh->dwc_tt);
 
@@ -1716,6 +1720,7 @@  int dwc2_hcd_qh_add(struct dwc2_hsotg *hsotg, struct dwc2_qh *qh)
 {
 	int status;
 	u32 intr_mask;
+	ktime_t delay;
 
 	if (dbg_qh(qh))
 		dev_vdbg(hsotg->dev, "%s()\n", __func__);
@@ -1734,8 +1739,8 @@  int dwc2_hcd_qh_add(struct dwc2_hsotg *hsotg, struct dwc2_qh *qh)
 			list_add_tail(&qh->qh_list_entry,
 				      &hsotg->non_periodic_sched_waiting);
 			qh->wait_timer_cancel = false;
-			mod_timer(&qh->wait_timer,
-				  jiffies + DWC2_RETRY_WAIT_DELAY + 1);
+			delay = ktime_set(0, DWC2_RETRY_WAIT_DELAY);
+			hrtimer_start(&qh->wait_timer, delay, HRTIMER_MODE_REL);
 		} else {
 			list_add_tail(&qh->qh_list_entry,
 				      &hsotg->non_periodic_sched_inactive);