Re: [RFC] Add EFI lock when creating new gauge record

[Heyi Guo <heyi.guo@linaro.org>]

[-- Attachment #1: Type: text/plain, Size: 2924 bytes --]

Hi Star,

Sorry to make a mistake with the code package :)

Please see my test results below.


在 11/24/2017 5:41 PM, Zeng, Star 写道:
> Good problem statement.
>
> EndGaugeEx and GetGaugeEx also need to be updated as they are operating same memory buffer, otherwise the performance data may be messed up.
>
> Another idea is to just use a global variable, for example mRecording, to prevent reentrance, but that there may be perf data missing.
>
> How to realize " not impacted much " in " the performance measuring data was not impacted much by this patch "?
> That means there is a little performance impact?
I tested more than 50 times on my platform with the original version and 
the modified one, and calculated the average "Total Duration", which 
were 32567ms and 32600ms respectively. So the performance impact almost 
can be ignored.
>
> Could you re-measure with all StartGaugeEx, EndGaugeEx and GetGaugeEx add lock?
Good point. The above result was tested with all of them locked.

I also attached my patch.

Thanks and regards,

Gary (Heyi Guo)
>
>
> Cc Liming.
>
>
> Thanks,
> Star
> -----Original Message-----
> From: edk2-devel [mailto:edk2-devel-bounces@lists.01.org] On Behalf Of Heyi Guo
> Sent: Friday, November 24, 2017 3:04 PM
> To: edk2-devel@lists.01.org
> Cc: Carsey, Jaben <jaben.carsey@intel.com>; Daryl McDaniel <edk2-lists@mc2research.org>
> Subject: [edk2] [RFC] Add EFI lock when creating new gauge record
>
> Hi folks,
>
> We got occasional system exceptions after enabling performance measuring feature in edk2. After debugging, we found there is potential memory overflow in DXE/DXE_CORE PerformanceLib when PERF_START is reentered, and reentrance is possible since we are supporting something like USB hot-plug, which is a timer event where gBS->ConnectController might be called and then PERF will be called in CoreConnectSingleController.
> However I can't reproduce the issue right now; please let me know if PERF reentrance is not theoretically possible in the latest edk2 code.
>
> When StartGaugeEx is being reentered, not only the gauge record might be overwritten, more serious situation will be caused if gauge data buffer reallocation procedure is interrupted, between line 180 and 187 in DxeCorePerformanceLib.c specifically. There, mMaxGaugeRecords will be doubled twice (denoted as 4X), but mGaugeData only points to a buffer of size 2X, which will probably cause the following 2X memory to be overflowed when gauge records are increased.
>
> My proposal is to add EFI lock with TPL notify in StartGaugeEx to avoid such situation. The test result seemed good on our platforms and the performance measuring data was not impacted much by this patch.
>
> Please let me know your comments.
>
> Thanks,
>
> Gary (Heyi Guo)
>
> _______________________________________________
> edk2-devel mailing list
> edk2-devel@lists.01.org
> https://lists.01.org/mailman/listinfo/edk2-devel


[-- Attachment #2: [PATCH] MdeModulePkg_PerformanceLib  add lock protection.eml --]
[-- Type: message/rfc822, Size: 9239 bytes --]

From: Heyi Guo <guoheyi@huawei.com>
To: <heyi.guo@linaro.org>
Cc: <phoenix.liyi@huawei.com>, <mengfanrong@huawei.com>, <zhangjinsong2@huawei.com>
Subject: [PATCH] MdeModulePkg/PerformanceLib: add lock protection
Date: Sat, 25 Nov 2017 16:42:29 +0800
Message-ID: <1511599349-93148-1-git-send-email-guoheyi@huawei.com>

From: Heyi Guo <heyi.guo@linaro.org>

DXE performance gauge record access functions might be reentered since
we are supporting something like USB hot-plug, which is a timer event
where gBS->ConnectController might be called and then PERF will be
called in CoreConnectSingleController.

When StartGaugeEx is being reentered, not only the gauge record might
be overwritten, more serious situation will be caused if gauge data
buffer reallocation procedure is interrupted, between line 180 and 187
in DxeCorePerformanceLib.c specifically. There, mMaxGaugeRecords will
be doubled twice (denoted as 4X), but mGaugeData only points to a
buffer of size 2X, which will probably cause the following 2X memory
to be overflowed when gauge records are increased.

So we add EFI lock with with TPL_NOTIFY in
StartGaugeEx/EndGaugeEx/GetGaugeEx to avoid memory overflow and gauge
data corruption.

Contributed-under: TianoCore Contribution Agreement 1.1
Signed-off-by: Heyi Guo <heyi.guo@linaro.org>
---
 .../DxeCorePerformanceLib/DxeCorePerformanceLib.c  | 67 +++++++++++++++++++++-
 1 file changed, 66 insertions(+), 1 deletion(-)

diff --git a/MdeModulePkg/Library/DxeCorePerformanceLib/DxeCorePerformanceLib.c b/MdeModulePkg/Library/DxeCorePerformanceLib/DxeCorePerformanceLib.c
index 51f488a..7c0e207 100644
--- a/MdeModulePkg/Library/DxeCorePerformanceLib/DxeCorePerformanceLib.c
+++ b/MdeModulePkg/Library/DxeCorePerformanceLib/DxeCorePerformanceLib.c
@@ -63,6 +63,11 @@ PERFORMANCE_EX_PROTOCOL mPerformanceExInterface = {
 
 PERFORMANCE_PROPERTY  mPerformanceProperty;
 
+//
+//  Gauge record lock to avoid data corruption or even memory overflow
+//
+STATIC EFI_LOCK mPerfRecordLock = EFI_INITIALIZE_LOCK_VARIABLE (TPL_NOTIFY);
+
 /**
   Searches in the gauge array with keyword Handle, Token, Module and Identifier.
 
@@ -162,6 +167,12 @@ StartGaugeEx (
   UINTN                     OldGaugeDataSize;
   GAUGE_DATA_HEADER         *OldGaugeData;
   UINT32                    Index;
+  EFI_STATUS                Status;
+
+  Status = EfiAcquireLockOrFail (&mPerfRecordLock);
+  if (EFI_ERROR (Status)) {
+    return Status;
+  }
 
   Index = mGaugeData->NumberOfEntries;
   if (Index >= mMaxGaugeRecords) {
@@ -175,6 +186,7 @@ StartGaugeEx (
 
     NewGaugeData = AllocateZeroPool (GaugeDataSize);
     if (NewGaugeData == NULL) {
+      EfiReleaseLock (&mPerfRecordLock);
       return EFI_OUT_OF_RESOURCES;
     }
 
@@ -209,6 +221,8 @@ StartGaugeEx (
 
   mGaugeData->NumberOfEntries++;
 
+  EfiReleaseLock (&mPerfRecordLock);
+
   return EFI_SUCCESS;
 }
 
@@ -250,6 +264,12 @@ EndGaugeEx (
 {
   GAUGE_DATA_ENTRY_EX *GaugeEntryExArray;
   UINT32              Index;
+  EFI_STATUS          Status;
+
+  Status = EfiAcquireLockOrFail (&mPerfRecordLock);
+  if (EFI_ERROR (Status)) {
+    return Status;
+  }
 
   if (TimeStamp == 0) {
     TimeStamp = GetPerformanceCounter ();
@@ -257,11 +277,13 @@ EndGaugeEx (
 
   Index = InternalSearchForGaugeEntry (Handle, Token, Module, Identifier);
   if (Index >= mGaugeData->NumberOfEntries) {
+    EfiReleaseLock (&mPerfRecordLock);
     return EFI_NOT_FOUND;
   }
   GaugeEntryExArray = (GAUGE_DATA_ENTRY_EX *) (mGaugeData + 1);
   GaugeEntryExArray[Index].EndTimeStamp = TimeStamp;
 
+  EfiReleaseLock (&mPerfRecordLock);
   return EFI_SUCCESS;
 }
 
@@ -274,6 +296,8 @@ EndGaugeEx (
   If it stands for a valid entry, then EFI_SUCCESS is returned and
   GaugeDataEntryEx stores the pointer to that entry.
 
+  This internal function is added to avoid releasing lock before each return statement.
+
   @param  LogEntryKey             The key for the previous performance measurement log entry.
                                   If 0, then the first performance measurement log entry is retrieved.
   @param  GaugeDataEntryEx        The indirect pointer to the extended gauge data entry specified by LogEntryKey
@@ -287,7 +311,7 @@ EndGaugeEx (
 **/
 EFI_STATUS
 EFIAPI
-GetGaugeEx (
+InternalGetGaugeEx (
   IN  UINTN                 LogEntryKey,
   OUT GAUGE_DATA_ENTRY_EX   **GaugeDataEntryEx
   )
@@ -314,6 +338,47 @@ GetGaugeEx (
 }
 
 /**
+  Retrieves a previously logged performance measurement.
+  It can also retrieve the log created by StartGauge and EndGauge of PERFORMANCE_PROTOCOL,
+  and then assign the Identifier with 0.
+
+  Retrieves the performance log entry from the performance log specified by LogEntryKey.
+  If it stands for a valid entry, then EFI_SUCCESS is returned and
+  GaugeDataEntryEx stores the pointer to that entry.
+
+  @param  LogEntryKey             The key for the previous performance measurement log entry.
+                                  If 0, then the first performance measurement log entry is retrieved.
+  @param  GaugeDataEntryEx        The indirect pointer to the extended gauge data entry specified by LogEntryKey
+                                  if the retrieval is successful.
+
+  @retval EFI_SUCCESS             The GuageDataEntryEx is successfully found based on LogEntryKey.
+  @retval EFI_NOT_FOUND           The LogEntryKey is the last entry (equals to the total entry number).
+  @retval EFI_INVALIDE_PARAMETER  The LogEntryKey is not a valid entry (greater than the total entry number).
+  @retval EFI_INVALIDE_PARAMETER  GaugeDataEntryEx is NULL.
+
+**/
+EFI_STATUS
+EFIAPI
+GetGaugeEx (
+  IN  UINTN                 LogEntryKey,
+  OUT GAUGE_DATA_ENTRY_EX   **GaugeDataEntryEx
+  )
+{
+  EFI_STATUS                Status;
+
+  Status = EfiAcquireLockOrFail (&mPerfRecordLock);
+  if (EFI_ERROR (Status)) {
+    return Status;
+  }
+
+  Status = InternalGetGaugeEx (LogEntryKey, GaugeDataEntryEx);
+
+  EfiReleaseLock (&mPerfRecordLock);
+
+  return Status;
+}
+
+/**
   Adds a record at the end of the performance measurement log
   that records the start time of a performance measurement.
 
-- 
2.8.1