Re: [edk2-devel] [PATCH v2 1/1] MdeModulePkg/XhciDxe: Fix Broken Timeouts

["Henz, Patrick" <patrick.henz@hpe.com>]

Hi Hao and Ray,

In regards to the behavior when Timeout == 0, I did try to account for that in my initial patch with the following logic:

	(0 == Timeout)?(EFI_TIMER_PERIOD_MICROSECONDS(0xFFFFFFFF)):(EFI_TIMER_PERIOD_MILLISECONDS(Timeout))

This results in a timeout that happens sooner than what the current code would produce, but it falls in line with what the original code seemed to intend to do. Ray suggested that I enhance the code by not creating the timer event when Timeout is 0, which I assumed meant that XhcExecTransfer () would just return. I personally think it would be a good idea to keep this behavior in the code, but would like Ray's input on the matter. Appreciate the help!

Thanks,
Patrick Henz

-----Original Message-----
From: devel@edk2.groups.io [mailto:devel@edk2.groups.io] On Behalf Of Wu, Hao A
Sent: Wednesday, September 2, 2020 9:25 PM
To: devel@edk2.groups.io; Henz, Patrick <patrick.henz@hpe.com>; Ni, Ray <ray.ni@intel.com>
Cc: Wang, Jian J <jian.j.wang@intel.com>
Subject: Re: [edk2-devel] [PATCH v2 1/1] MdeModulePkg/XhciDxe: Fix Broken Timeouts

Hello Patrick, a couple of inline comments below.
Hello Ray, need your input on one thing below as well.


> -----Original Message-----
> From: devel@edk2.groups.io <devel@edk2.groups.io> On Behalf Of 
> patrick.henz@hpe.com
> Sent: Thursday, September 3, 2020 1:05 AM
> To: devel@edk2.groups.io
> Cc: Patrick Henz <patrick.henz@hpe.com>; Wang, Jian J 
> <jian.j.wang@intel.com>; Wu, Hao A <hao.a.wu@intel.com>; Ni, Ray 
> <ray.ni@intel.com>
> Subject: [edk2-devel] [PATCH v2 1/1] MdeModulePkg/XhciDxe: Fix Broken 
> Timeouts
> 
> From: Patrick Henz <patrick.henz@hpe.com>
> 
> REF:INVALID URI REMOVED
> ocore.org_show-5Fbug.cgi-3Fid-3D2948&d=DwIFAg&c=C5b8zRQO1miGmBeVZ2LFWg
> &r=wx4n0HbqxSAP19Eklmv6gq7ivDQlqQ_ITOkZIBUNNKg&m=OKlWpRL8ZyDfhUEh6S4OU
> aMasig0MPoajX7Vz2sDSvY&s=LTDbPsspkRCcWFBfThqhR_FaljF2kQLagB_t-kbAm80&e
> =
> 
> Timeouts in the XhciDxe driver are taking longer than expected due to 
> the timeout loops not accounting for code execution time. As en 
> example, 5 second timeouts have been observed to take around 36 
> seconds to complete.
> Use SetTimer and Create/CheckEvent from Boot Services to determine 
> when timeout occurred.
> 
> Cc: Jian J Wang <jian.j.wang@intel.com>
> Cc: Hao A Wu <hao.a.wu@intel.com>
> Cc: Ray Ni <ray.ni@intel.com>
> Signed-off-by: Patrick Henz <patrick.henz@hpe.com>
> ---
>  MdeModulePkg/Bus/Pci/XhciDxe/XhciReg.c   | 35 ++++++++++++++++---
>  MdeModulePkg/Bus/Pci/XhciDxe/XhciSched.c | 43
> +++++++++++++++++++-----
>  2 files changed, 65 insertions(+), 13 deletions(-)
> 
> diff --git a/MdeModulePkg/Bus/Pci/XhciDxe/XhciReg.c
> b/MdeModulePkg/Bus/Pci/XhciDxe/XhciReg.c
> index 42b773ab31be..33ac13504669 100644
> --- a/MdeModulePkg/Bus/Pci/XhciDxe/XhciReg.c
> +++ b/MdeModulePkg/Bus/Pci/XhciDxe/XhciReg.c
> @@ -442,17 +442,44 @@ XhcWaitOpRegBit (
>    IN UINT32               Timeout
>    )
>  {
> -  UINT32                  Index;
> -  UINT64                  Loop;
> +  EFI_STATUS Status;
> +  EFI_EVENT  TimeoutEvent;
> 
> -  Loop   = Timeout * XHC_1_MILLISECOND;
> +  TimeoutEvent = NULL;
> 
> -  for (Index = 0; Index < Loop; Index++) {
> +  if (Timeout == 0) {
> +    goto TIMEOUT;
> +  }
> +
> +  Status = gBS->CreateEvent (
> +                  EVT_TIMER,
> +                  TPL_CALLBACK,
> +                  NULL,
> +                  NULL,
> +                  &TimeoutEvent
> +                  );
> +
> +  if (!EFI_ERROR (Status)) {
> +    Status = gBS->SetTimer (TimeoutEvent,
> +                            TimerRelative,
> +                            EFI_TIMER_PERIOD_MILLISECONDS(Timeout));
> +  }
> +
> +  if (EFI_ERROR(Status)) {
> +    goto TIMEOUT;
> +  }


Could you help to refine the return status for the case when CreateEvent or SetTimer calls fail?
I think it will return EFI_TIMEOUT at this moment, which might confuse the caller.
You may need to modify the function description comment section for the new return value also.

A similar case applies to XhcExecTransfer() as well.


> +
> +  do {
>      if (XHC_REG_BIT_IS_SET (Xhc, Offset, Bit) == WaitToSet) {
>        return EFI_SUCCESS;
>      }
> 
>      gBS->Stall (XHC_1_MICROSECOND);
> +  } while (EFI_ERROR(gBS->CheckEvent (TimeoutEvent)));
> +
> +TIMEOUT:
> +  if (TimeoutEvent != NULL) {
> +    gBS->CloseEvent (TimeoutEvent);
>    }
> 
>    return EFI_TIMEOUT;
> diff --git a/MdeModulePkg/Bus/Pci/XhciDxe/XhciSched.c
> b/MdeModulePkg/Bus/Pci/XhciDxe/XhciSched.c
> index ab8957c546ee..d6290b5fe33b 100644
> --- a/MdeModulePkg/Bus/Pci/XhciDxe/XhciSched.c
> +++ b/MdeModulePkg/Bus/Pci/XhciDxe/XhciSched.c
> @@ -1273,11 +1273,19 @@ XhcExecTransfer (
>    )
>  {
>    EFI_STATUS              Status;
> -  UINTN                   Index;
> -  UINT64                  Loop;
>    UINT8                   SlotId;
>    UINT8                   Dci;
>    BOOLEAN                 Finished;
> +  EFI_EVENT               TimeoutEvent;
> +  EFI_STATUS              TimerStatus;
> +
> +  Status       = EFI_SUCCESS;
> +  Finished     = FALSE;
> +  TimeoutEvent = NULL;
> +
> +  if (Timeout == 0) {
> +    goto DONE;
> +  }
> 
>    if (CmdTransfer) {
>      SlotId = 0;
> @@ -1291,29 +1299,46 @@ XhcExecTransfer (
>      ASSERT (Dci < 32);
>    }
> 
> -  Status = EFI_SUCCESS;
> -  Loop   = Timeout * XHC_1_MILLISECOND;
> -  if (Timeout == 0) {
> -    Loop = 0xFFFFFFFF;


Ray and Patrick, the previous behavior when 'Timeout' is 0 for this function is that it will do a 'psudo-indefinite' loop by setting the 'Loop' variable to the value of MAX_UINT32.

But after the patch, the behavior got changed and the function will directly return EFI_TIMEOUT when 'Timeout' is 0.
This behavior change might impact the callers when they expecting a 'psudo-indefinite' timeout.
I think it would be better to keep the origin behavior, what is your thought?

Best Regards,
Hao Wu


> +  TimerStatus = gBS->CreateEvent (
> +                       EVT_TIMER,
> +                       TPL_CALLBACK,
> +                       NULL,
> +                       NULL,
> +                       &TimeoutEvent
> +                       );
> +
> +  if (!EFI_ERROR (TimerStatus)) {
> +    TimerStatus = gBS->SetTimer (TimeoutEvent,
> +                                 TimerRelative,
> +
> + EFI_TIMER_PERIOD_MILLISECONDS(Timeout));
> +  }
> +
> +  if (EFI_ERROR (TimerStatus)) {
> +    goto DONE;
>    }
> 
>    XhcRingDoorBell (Xhc, SlotId, Dci);
> 
> -  for (Index = 0; Index < Loop; Index++) {
> +  do {
>      Finished = XhcCheckUrbResult (Xhc, Urb);
>      if (Finished) {
>        break;
>      }
>      gBS->Stall (XHC_1_MICROSECOND);
> -  }
> +  } while (EFI_ERROR(gBS->CheckEvent (TimeoutEvent)));
> 
> -  if (Index == Loop) {
> +DONE:
> +  if (!Finished) {
>      Urb->Result = EFI_USB_ERR_TIMEOUT;
>      Status      = EFI_TIMEOUT;
>    } else if (Urb->Result != EFI_USB_NOERROR) {
>      Status      = EFI_DEVICE_ERROR;
>    }
> 
> +  if (TimeoutEvent != NULL) {
> +    gBS->CloseEvent (TimeoutEvent);
> +  }
> +
>    return Status;
>  }
> 
> --
> 2.28.0
> 
> 
>