From d9e7f6fe49738421c02381425d289767d7055ef1 Mon Sep 17 00:00:00 2001
From: Rebecca Cran <rebecca@quicinc.com>
Date: Tue, 6 Dec 2022 22:30:39 +0800
Subject: [PATCH] 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>
Reviewed-by: Hao A Wu <hao.a.wu@intel.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 0b7270f4e9..e903593b01 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 @@ ON_EXIT:
   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 5da26afbe1..6967aabceb 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 c05431ff30..15fb49f28f 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 13b0400e83..13247f7b0d 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.39.2