Re: [edk2-devel] [PATCH v2 1/1] MdeModulePkg: Put USB DEBUGs that occur for bulk timeouts under VERBOSE

["Wu, Hao A" <hao.a.wu@intel.com>]

Pushed via:
PR - https://github.com/tianocore/edk2/pull/3733
Commit - https://github.com/tianocore/edk2/commit/d9e7f6fe49738421c02381425d289767d7055ef1

Best Regards,
Hao Wu

> -----Original Message-----
> From: devel@edk2.groups.io <devel@edk2.groups.io> On Behalf Of Wu, Hao
> A
> Sent: Wednesday, December 7, 2022 9:08 AM
> To: Rebecca Cran <rebecca@quicinc.com>; devel@edk2.groups.io; Gao,
> Liming <gaoliming@byosoft.com.cn>; Ni, Ray <ray.ni@intel.com>; Wang,
> Jian J <jian.j.wang@intel.com>
> Subject: Re: [edk2-devel] [PATCH v2 1/1] MdeModulePkg: Put USB DEBUGs
> that occur for bulk timeouts under VERBOSE
> 
> Reviewed-by: Hao A Wu <hao.a.wu@intel.com>
> Will wait a couple of days before merging to see if comments from other
> reviewers.
> 
> Best Regards,
> Hao Wu
> 
> > -----Original Message-----
> > From: Rebecca Cran <rebecca@quicinc.com>
> > Sent: Tuesday, December 6, 2022 10:31 PM
> > To: devel@edk2.groups.io; Gao, Liming <gaoliming@byosoft.com.cn>; Ni,
> > Ray <ray.ni@intel.com>; Wang, Jian J <jian.j.wang@intel.com>; Wu, Hao A
> > <hao.a.wu@intel.com>
> > Cc: Rebecca Cran <rebecca@quicinc.com>
> > Subject: [PATCH v2 1/1] MdeModulePkg: Put USB DEBUGs that occur for
> bulk
> > timeouts under VERBOSE
> >
> > With the pending commit of UsbNetworkPkg, it will become common for
> > UsbBulkTransfer calls to timeout, given that the drivers are called from
> > MnpSystemPoll every MNP_SYS_POLL_INTERVAL milliseconds: the drivers
> > check for network packets by calling UsbBulkTransfer with a timeout of
> > 1ms.
> >
> > Avoid console spam by moving DEBUG messages that occur each time a
> bulk
> > transfer request times out from DEBUG_ERROR to DEBUG_VERBOSE, for
> > both
> > EHCI and XHCI drivers.
> >
> > Signed-off-by: Rebecca Cran <rebecca@quicinc.com>
> > ---
> >  MdeModulePkg/Bus/Pci/EhciDxe/Ehci.c      | 9 ++++++++-
> >  MdeModulePkg/Bus/Pci/EhciDxe/EhciSched.c | 2 +-
> >  MdeModulePkg/Bus/Pci/XhciDxe/Xhci.c      | 9 ++++++++-
> >  MdeModulePkg/Bus/Pci/XhciDxe/XhciSched.c | 6 +++---
> >  4 files changed, 20 insertions(+), 6 deletions(-)
> >
> > diff --git a/MdeModulePkg/Bus/Pci/EhciDxe/Ehci.c
> > b/MdeModulePkg/Bus/Pci/EhciDxe/Ehci.c
> > index 0b7270f4e930..e903593b0198 100644
> > --- a/MdeModulePkg/Bus/Pci/EhciDxe/Ehci.c
> > +++ b/MdeModulePkg/Bus/Pci/EhciDxe/Ehci.c
> > @@ -848,6 +848,7 @@ EhcBulkTransfer (
> >    URB          *Urb;
> >    EFI_TPL      OldTpl;
> >    EFI_STATUS   Status;
> > +  UINTN        DebugErrorLevel;
> >
> >    //
> >    // Validate the parameters
> > @@ -932,7 +933,13 @@ EhcBulkTransfer (
> >    gBS->RestoreTPL (OldTpl);
> >
> >    if (EFI_ERROR (Status)) {
> > -    DEBUG ((DEBUG_ERROR, "EhcBulkTransfer: error - %r, transfer - %x\n",
> > Status, *TransferResult));
> > +    if (Status == EFI_TIMEOUT) {
> > +      DebugErrorLevel = DEBUG_VERBOSE;
> > +    } else {
> > +      DebugErrorLevel = DEBUG_ERROR;
> > +    }
> > +
> > +    DEBUG ((DebugErrorLevel, "EhcBulkTransfer: error - %r, transfer -
>  %x\n",
> > Status, *TransferResult));
> >    }
> >
> >    return Status;
> > diff --git a/MdeModulePkg/Bus/Pci/EhciDxe/EhciSched.c
> > b/MdeModulePkg/Bus/Pci/EhciDxe/EhciSched.c
> > index 5da26afbe120..6967aabceb78 100644
> > --- a/MdeModulePkg/Bus/Pci/EhciDxe/EhciSched.c
> > +++ b/MdeModulePkg/Bus/Pci/EhciDxe/EhciSched.c
> > @@ -702,7 +702,7 @@ EhcExecTransfer (
> >    }
> >
> >    if (!Finished) {
> > -    DEBUG ((DEBUG_ERROR, "EhcExecTransfer: transfer not finished
> > in %dms\n", (UINT32)TimeOut));
> > +    DEBUG ((DEBUG_VERBOSE, "EhcExecTransfer: transfer not finished
> > in %dms\n", (UINT32)TimeOut));
> >      EhcDumpQh (Urb->Qh, NULL, FALSE);
> >
> >      Status = EFI_TIMEOUT;
> > diff --git a/MdeModulePkg/Bus/Pci/XhciDxe/Xhci.c
> > b/MdeModulePkg/Bus/Pci/XhciDxe/Xhci.c
> > index c05431ff30ec..15fb49f28fa0 100644
> > --- a/MdeModulePkg/Bus/Pci/XhciDxe/Xhci.c
> > +++ b/MdeModulePkg/Bus/Pci/XhciDxe/Xhci.c
> > @@ -1242,6 +1242,7 @@ XhcBulkTransfer (
> >    UINT8              SlotId;
> >    EFI_STATUS         Status;
> >    EFI_TPL            OldTpl;
> > +  UINTN              DebugErrorLevel;
> >
> >    //
> >    // Validate the parameters
> > @@ -1304,7 +1305,13 @@ XhcBulkTransfer (
> >
> >  ON_EXIT:
> >    if (EFI_ERROR (Status)) {
> > -    DEBUG ((DEBUG_ERROR, "XhcBulkTransfer: error - %r, transfer - %x\n",
> > Status, *TransferResult));
> > +    if (Status == EFI_TIMEOUT) {
> > +      DebugErrorLevel = DEBUG_VERBOSE;
> > +    } else {
> > +      DebugErrorLevel = DEBUG_ERROR;
> > +    }
> > +
> > +    DEBUG ((DebugErrorLevel, "XhcBulkTransfer: error - %r, transfer -
>  %x\n",
> > Status, *TransferResult));
> >    }
> >
> >    gBS->RestoreTPL (OldTpl);
> > diff --git a/MdeModulePkg/Bus/Pci/XhciDxe/XhciSched.c
> > b/MdeModulePkg/Bus/Pci/XhciDxe/XhciSched.c
> > index 13b0400e83d7..13247f7b0dfc 100644
> > --- a/MdeModulePkg/Bus/Pci/XhciDxe/XhciSched.c
> > +++ b/MdeModulePkg/Bus/Pci/XhciDxe/XhciSched.c
> > @@ -734,7 +734,7 @@ XhcDequeueTrbFromEndpoint (
> >    Dci = XhcEndpointToDci (Urb->Ep.EpAddr, (UINT8)(Urb->Ep.Direction));
> >    ASSERT (Dci < 32);
> >
> > -  DEBUG ((DEBUG_INFO, "Stop Slot = %x,Dci = %x\n", SlotId, Dci));
> > +  DEBUG ((DEBUG_VERBOSE, "Stop Slot = %x,Dci = %x\n", SlotId, Dci));
> >
> >    //
> >    // 1) Send Stop endpoint command to stop xHC from executing of the TDs
> > on the endpoint
> > @@ -3376,7 +3376,7 @@ XhcStopEndpoint (
> >    EVT_TRB_COMMAND_COMPLETION  *EvtTrb;
> >    CMD_TRB_STOP_ENDPOINT       CmdTrbStopED;
> >
> > -  DEBUG ((DEBUG_INFO, "XhcStopEndpoint: Slot = 0x%x, Dci = 0x%x\n",
> > SlotId, Dci));
> > +  DEBUG ((DEBUG_VERBOSE, "XhcStopEndpoint: Slot = 0x%x, Dci =
> 0x%x\n",
> > SlotId, Dci));
> >
> >    //
> >    // When XhcCheckUrbResult waits for the Stop_Endpoint completion, it
> > also checks
> > @@ -3497,7 +3497,7 @@ XhcSetTrDequeuePointer (
> >    CMD_SET_TR_DEQ_POINTER      CmdSetTRDeq;
> >    EFI_PHYSICAL_ADDRESS        PhyAddr;
> >
> > -  DEBUG ((DEBUG_INFO, "XhcSetTrDequeuePointer: Slot = 0x%x, Dci =
> 0x%x,
> > Urb = 0x%x\n", SlotId, Dci, Urb));
> > +  DEBUG ((DEBUG_VERBOSE, "XhcSetTrDequeuePointer: Slot = 0x%x, Dci =
> > 0x%x, Urb = 0x%x\n", SlotId, Dci, Urb));
> >
> >    //
> >    // Send stop endpoint command to transit Endpoint from running to stop
> > state
> > --
> > 2.30.2
> 
> 
> 
> 
>