From d269a99999db22f015c61acf8d610e7078b64b3e Mon Sep 17 00:00:00 2001 From: kuqin12 <42554914+kuqin12@users.noreply.github.com> Date: Thu, 18 Jan 2024 10:34:13 -0800 Subject: [PATCH] Wrap advanced logger buffer cursor when the logging area is full (#408) ## Description The advanced logging at runtime is lack of usage. However, this becomes increasingly important for server platforms, where the system could potentially stay up for months, or even years. This will make the advanced logger fill up the buffer during runtime/MM logging well ahead of a reset event, making the buffer content stale when being reviewed. This change added a feature PCD guarded feature that, when enabled, will automatically wrap the LogCurrent cursor to the beginning and continue to log. This will effectively create a circular buffer as the stale content will remain in place. The tooling update is still under development. - [x] Impacts functionality? - **Functionality** - Does the change ultimately impact how firmware functions? - Examples: Add a new library, publish a new PPI, update an algorithm, ... - [ ] Impacts security? - **Security** - Does the change have a direct security impact on an application, flow, or firmware? - Examples: Crypto algorithm change, buffer overflow fix, parameter validation improvement, ... - [ ] Breaking change? - **Breaking change** - Will anyone consuming this change experience a break in build or boot behavior? - Examples: Add a new library class, move a module to a different repo, call a function in a new library class in a pre-existing module, ... - [x] Includes tests? - **Tests** - Does the change include any explicit test code? - Examples: Unit tests, integration tests, robot tests, ... - [ ] Includes documentation? - **Documentation** - Does the change contain explicit documentation additions outside direct code modifications (and comments)? - Examples: Update readme file, add feature readme file, link to documentation on an a separate Web page, ... ## How This Was Tested This was tested on QEMU Q35 along with the UEFI shell based test app to verify that the entry after wrapping is correct and is multi-threading safe. ## Integration Instructions Platforms can enable this feature by setting `gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerAutoClearEnable|TRUE` --- AdvLoggerPkg/AdvLoggerPkg.dec | 5 + AdvLoggerPkg/AdvLoggerPkg.dsc | 1 + .../AdvancedLoggerLib/AdvancedLoggerCommon.c | 52 +- .../BaseArm/AdvancedLoggerLib.inf | 3 + .../DxeCore/AdvancedLoggerLib.inf | 1 + .../MmCore/AdvancedLoggerLib.inf | 3 + .../MmCoreArm/AdvancedLoggerLib.inf | 1 + .../Pei64/AdvancedLoggerLib.inf | 1 + .../PeiCore/AdvancedLoggerLib.inf | 1 + .../Runtime/AdvancedLoggerLib.inf | 3 + .../Sec/AdvancedLoggerLib.inf | 3 + .../SmmCore/AdvancedLoggerLib.inf | 3 + .../AdvancedLoggerWrapperTestApp.c | 509 ++++++++++++++++++ .../AdvancedLoggerWrapperTestApp.inf | 49 ++ 14 files changed, 621 insertions(+), 14 deletions(-) create mode 100644 AdvLoggerPkg/UnitTests/AdvancedLoggerWrapper/AdvancedLoggerWrapperTestApp.c create mode 100644 AdvLoggerPkg/UnitTests/AdvancedLoggerWrapper/AdvancedLoggerWrapperTestApp.inf diff --git a/AdvLoggerPkg/AdvLoggerPkg.dec b/AdvLoggerPkg/AdvLoggerPkg.dec index e7876b8712..d1841dc4ae 100644 --- a/AdvLoggerPkg/AdvLoggerPkg.dec +++ b/AdvLoggerPkg/AdvLoggerPkg.dec @@ -81,6 +81,11 @@ # gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedFileLoggerForceEnable|TRUE|BOOLEAN|0x00010184 + ## PcdAdvancedLoggerAutoWrapEnable - Automatically wrap around the LogCurrent cursor when it reaches the end + # of the log. This feature only activates at runtime (after exit boot service event). + # + gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerAutoWrapEnable|FALSE|BOOLEAN|0x00010188 + [PcdsFixedAtBuild] ## Advanced Logger Base - NULL = UEFI starts with PEI or DXE, and there is no SEC, or SEC diff --git a/AdvLoggerPkg/AdvLoggerPkg.dsc b/AdvLoggerPkg/AdvLoggerPkg.dsc index 40e3865d87..d6b2279814 100644 --- a/AdvLoggerPkg/AdvLoggerPkg.dsc +++ b/AdvLoggerPkg/AdvLoggerPkg.dsc @@ -151,6 +151,7 @@ AdvLoggerPkg/Library/AssertLib/AssertLib.inf AdvLoggerPkg/Library/AssertTelemetryLib/AssertLib.inf AdvLoggerPkg/UnitTests/LineParser/LineParserTestApp.inf + AdvLoggerPkg/UnitTests/AdvancedLoggerWrapper/AdvancedLoggerWrapperTestApp.inf [BuildOptions] #force deprecated interfaces off diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/AdvancedLoggerCommon.c b/AdvLoggerPkg/Library/AdvancedLoggerLib/AdvancedLoggerCommon.c index bfd601c923..fee60ecf38 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/AdvancedLoggerCommon.c +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/AdvancedLoggerCommon.c @@ -69,20 +69,44 @@ AdvancedLoggerMemoryLoggerWrite ( if ((UsedSize >= LoggerInfo->LogBufferSize) || ((LoggerInfo->LogBufferSize - UsedSize) < EntrySize)) { - // - // Update the number of bytes of log that have not been captured - // - do { - CurrentSize = LoggerInfo->DiscardedSize; - NewSize = CurrentSize + (UINT32)NumberOfBytes; - OldSize = InterlockedCompareExchange32 ( - (UINT32 *)&LoggerInfo->DiscardedSize, - (UINT32)CurrentSize, - (UINT32)NewSize - ); - } while (OldSize != CurrentSize); - - return LoggerInfo; + if (FeaturePcdGet (PcdAdvancedLoggerAutoWrapEnable) && (LoggerInfo->AtRuntime)) { + // + // Wrap around the current cursor when auto wrap is enabled on buffer full during runtime. + // + NewBuffer = LoggerInfo->LogBuffer; + OldValue = InterlockedCompareExchange64 ( + (UINT64 *)&LoggerInfo->LogCurrent, + (UINT64)CurrentBuffer, + (UINT64)NewBuffer + ); + if (OldValue != CurrentBuffer) { + // + // Another thread has updated the buffer, we should retry the logging. + // + continue; + } + + // Now that we have a buffer that starts from the beginning, proceed to log the current message, from the beginning. + // Note that in this case, if there are other threads in the middle of logging a message, they will continue to write + // to the end of the buffer as it fits. + // If there is another clearing attempt on the other thread, i.e. another thread also try to fill up the buffer, the + // first clear will take effect and the other log entries will fail to update and proceed with a normal retry. + } else { + // + // Update the number of bytes of log that have not been captured + // + do { + CurrentSize = LoggerInfo->DiscardedSize; + NewSize = CurrentSize + (UINT32)NumberOfBytes; + OldSize = InterlockedCompareExchange32 ( + (UINT32 *)&LoggerInfo->DiscardedSize, + (UINT32)CurrentSize, + (UINT32)NewSize + ); + } while (OldSize != CurrentSize); + + return LoggerInfo; + } } NewBuffer = PA_FROM_PTR ((CHAR8_FROM_PA (CurrentBuffer) + EntrySize)); diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/BaseArm/AdvancedLoggerLib.inf b/AdvLoggerPkg/Library/AdvancedLoggerLib/BaseArm/AdvancedLoggerLib.inf index 10db7ffc89..ac2385f122 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/BaseArm/AdvancedLoggerLib.inf +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/BaseArm/AdvancedLoggerLib.inf @@ -40,5 +40,8 @@ gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerBase ## CONSUMES gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerHdwPortDebugPrintErrorLevel ## SOMETIMES_CONSUMES +[FeaturePcd] + gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerAutoWrapEnable + [Depex] TRUE diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/DxeCore/AdvancedLoggerLib.inf b/AdvLoggerPkg/Library/AdvancedLoggerLib/DxeCore/AdvancedLoggerLib.inf index ac29b75e39..9341e96ec0 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/DxeCore/AdvancedLoggerLib.inf +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/DxeCore/AdvancedLoggerLib.inf @@ -61,3 +61,4 @@ [FeaturePcd] gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerLocator gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerFixedInRAM + gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerAutoWrapEnable diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/MmCore/AdvancedLoggerLib.inf b/AdvLoggerPkg/Library/AdvancedLoggerLib/MmCore/AdvancedLoggerLib.inf index eac348b636..692ddbc9e3 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/MmCore/AdvancedLoggerLib.inf +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/MmCore/AdvancedLoggerLib.inf @@ -43,5 +43,8 @@ [Pcd] gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerHdwPortDebugPrintErrorLevel ## SOMETIMES_CONSUMES +[FeaturePcd] + gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerAutoWrapEnable + [Depex] TRUE diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/MmCoreArm/AdvancedLoggerLib.inf b/AdvLoggerPkg/Library/AdvancedLoggerLib/MmCoreArm/AdvancedLoggerLib.inf index 4de474cab0..b4f06d49d3 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/MmCoreArm/AdvancedLoggerLib.inf +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/MmCoreArm/AdvancedLoggerLib.inf @@ -43,6 +43,7 @@ [FeaturePcd] gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerFixedInRAM + gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerAutoWrapEnable [FixedPcd] gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerBase diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/Pei64/AdvancedLoggerLib.inf b/AdvLoggerPkg/Library/AdvancedLoggerLib/Pei64/AdvancedLoggerLib.inf index 5293106094..24212612e3 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/Pei64/AdvancedLoggerLib.inf +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/Pei64/AdvancedLoggerLib.inf @@ -40,3 +40,4 @@ [Pcd] gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerBase ## CONSUMES gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerHdwPortDebugPrintErrorLevel ## SOMETIMES_CONSUMES + gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerAutoWrapEnable ## SOMETIMES_CONSUMES diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/PeiCore/AdvancedLoggerLib.inf b/AdvLoggerPkg/Library/AdvancedLoggerLib/PeiCore/AdvancedLoggerLib.inf index 85087b7ac9..9ba99c4f33 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/PeiCore/AdvancedLoggerLib.inf +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/PeiCore/AdvancedLoggerLib.inf @@ -54,6 +54,7 @@ [FeaturePcd] gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerPeiInRAM ## CONSUMES gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerFixedInRAM ## CONSUMES + gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerAutoWrapEnable [FixedPcd] gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerBase ## CONSUMES diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/Runtime/AdvancedLoggerLib.inf b/AdvLoggerPkg/Library/AdvancedLoggerLib/Runtime/AdvancedLoggerLib.inf index eb9f355af1..0bbb5b22d7 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/Runtime/AdvancedLoggerLib.inf +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/Runtime/AdvancedLoggerLib.inf @@ -44,3 +44,6 @@ [Pcd] gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerHdwPortDebugPrintErrorLevel ## SOMETIMES_CONSUMES + +[FeaturePcd] + gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerAutoWrapEnable diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/Sec/AdvancedLoggerLib.inf b/AdvLoggerPkg/Library/AdvancedLoggerLib/Sec/AdvancedLoggerLib.inf index 976f03d134..dda7930bf1 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/Sec/AdvancedLoggerLib.inf +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/Sec/AdvancedLoggerLib.inf @@ -47,5 +47,8 @@ gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerPages ## CONSUMES gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerHdwPortDebugPrintErrorLevel ## CONSUMES +[FeaturePcd] + gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerAutoWrapEnable + [BuildOptions] *_*_*_CC_FLAGS = -D ADVANCED_LOGGER_SEC=1 diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/SmmCore/AdvancedLoggerLib.inf b/AdvLoggerPkg/Library/AdvancedLoggerLib/SmmCore/AdvancedLoggerLib.inf index 480a989d6e..552e50fd7d 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/SmmCore/AdvancedLoggerLib.inf +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/SmmCore/AdvancedLoggerLib.inf @@ -46,3 +46,6 @@ [Pcd] gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerHdwPortDebugPrintErrorLevel ## SOMETIMES_CONSUMES + +[FeaturePcd] + gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerAutoWrapEnable diff --git a/AdvLoggerPkg/UnitTests/AdvancedLoggerWrapper/AdvancedLoggerWrapperTestApp.c b/AdvLoggerPkg/UnitTests/AdvancedLoggerWrapper/AdvancedLoggerWrapperTestApp.c new file mode 100644 index 0000000000..c6e331116d --- /dev/null +++ b/AdvLoggerPkg/UnitTests/AdvancedLoggerWrapper/AdvancedLoggerWrapperTestApp.c @@ -0,0 +1,509 @@ +/** @file +AdvancedLoggerWrapperTestApp.c + +This is a Unit Test for the AdvancedLoggerWrapper code. + +Copyright (C) Microsoft Corporation. All rights reserved. +SPDX-License-Identifier: BSD-2-Clause-Patent + +**/ + +#include +#include + +#include +#include +#include + +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include + +#define UNIT_TEST_APP_NAME "AdvancedLoggerWrapper Library test cases" +#define UNIT_TEST_APP_VERSION "1.0" +#define ADV_TIME_STAMP_PREFIX "hh:mm:ss:ttt : " +#define ADV_TIME_STAMP_PREFIX_LEN (sizeof (ADV_TIME_STAMP_PREFIX) - sizeof (CHAR8)) +#define ADV_TIME_TEST_STR "Test" +#define ADV_WRAP_TEST_STR "DEADBEEF\n" + +// The following text represents the output lines from the line parser given the above input + +/* spell-checker: disable */ +CHAR8 Line00[] = "09:06:45.012 : [DXE] DEADBEEF\n"; +CHAR8 Line01[] = "09:06:45.012 : [DXE] 00000000DEADBEEF\n"; + +extern CONST CHAR8 *AdvMsgEntryPrefix[ADVANCED_LOGGER_PHASE_CNT]; + +ADVANCED_LOGGER_ACCESS_MESSAGE_LINE_ENTRY mMessageEntry; +ADVANCED_LOGGER_INFO *mLoggerInfo; +EFI_PHYSICAL_ADDRESS mMaxAddress = 0; +UINT32 mBufferSize = 0; +EFI_MP_SERVICES_PROTOCOL *mMpServicesProtocol = NULL; + +typedef struct { + CHAR8 *IdString; + CHAR8 *ExpectedLine; + VOID *MemoryToFree; + EFI_STATUS ExpectedStatus; +} BASIC_TEST_CONTEXT; + +// *----------------------------------------------------------------------------------* +// * Test Contexts * +// *----------------------------------------------------------------------------------* +STATIC BASIC_TEST_CONTEXT mTest00 = { "Basic tests", Line00, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest01 = { "Basic tests in MP", Line01, NULL, EFI_SUCCESS }; + +/// ================================================================================================ +/// ================================================================================================ +/// +/// HELPER FUNCTIONS +/// +/// ================================================================================================ +/// ================================================================================================ + +/** + ValidateInfoBlock + + The address of the ADVANCE_LOGGER_INFO block pointer is captured before END_OF_DXE. The + pointers LogBuffer and LogCurrent, and LogBufferSize, could be written to by untrusted code. Here, we check that + the pointers are within the allocated LoggerInfo space, and that LogBufferSize, which is used in multiple places + to see if a new message will fit into the log buffer, is valid. + + @param NONE + + @return BOOLEAN TRUE - mInforBlock passes security checks + @return BOOLEAN FALSE- mInforBlock failed security checks +**/ +STATIC +BOOLEAN +ValidateInfoBlock ( + VOID + ) +{ + if (mLoggerInfo == NULL) { + return FALSE; + } + + if (mLoggerInfo->Signature != ADVANCED_LOGGER_SIGNATURE) { + return FALSE; + } + + if (mLoggerInfo->LogBuffer != PA_FROM_PTR (mLoggerInfo + 1)) { + return FALSE; + } + + if ((mLoggerInfo->LogCurrent > mMaxAddress) || + (mLoggerInfo->LogCurrent < mLoggerInfo->LogBuffer)) + { + return FALSE; + } + + if (mLoggerInfo->LogBufferSize != mBufferSize) { + return FALSE; + } + + return TRUE; +} + +/** + CleanUpTestContext + + Cleans up after a test case. Free any allocated buffers if a test + takes the error exit. +**/ +STATIC +VOID +EFIAPI +CleanUpTestContext ( + IN UNIT_TEST_CONTEXT Context + ) +{ + BASIC_TEST_CONTEXT *Btc; + + Btc = (BASIC_TEST_CONTEXT *)Context; + + if (NULL != Btc->MemoryToFree) { + FreePool (Btc->MemoryToFree); + Btc->MemoryToFree = NULL; + } + + ZeroMem (&mMessageEntry, sizeof (mMessageEntry)); +} + +/// ================================================================================================ +/// ================================================================================================ +/// +/// TEST CASES +/// +/// ================================================================================================ +/// ================================================================================================ + +/* + Initialize LoggerInfo for tracking the test progress +*/ +STATIC +UNIT_TEST_STATUS +EFIAPI +InitializeInMemoryLog ( + IN UNIT_TEST_CONTEXT Context + ) +{ + ADVANCED_LOGGER_PROTOCOL *LoggerProtocol; + EFI_STATUS Status; + + if (gBS == NULL) { + return UNIT_TEST_ERROR_PREREQUISITE_NOT_MET; + } + + // Make sure the wrapper feature is enabled. + if (!FeaturePcdGet (PcdAdvancedLoggerAutoWrapEnable)) { + return UNIT_TEST_ERROR_TEST_FAILED; + } + + // + // Locate the Logger Information block. + // + Status = gBS->LocateProtocol ( + &gAdvancedLoggerProtocolGuid, + NULL, + (VOID **)&LoggerProtocol + ); + if (!EFI_ERROR (Status)) { + mLoggerInfo = LOGGER_INFO_FROM_PROTOCOL (LoggerProtocol); + if (mLoggerInfo != NULL) { + mMaxAddress = mLoggerInfo->LogBuffer + mLoggerInfo->LogBufferSize; + mBufferSize = mLoggerInfo->LogBufferSize; + } + + if (!ValidateInfoBlock ()) { + mLoggerInfo = NULL; + } + + // This is to bypass the restriction on runtime check. + mLoggerInfo->AtRuntime = TRUE; + } else { + return UNIT_TEST_ERROR_PREREQUISITE_NOT_MET; + } + + // Get ahold of the MP services protocol + Status = gBS->LocateProtocol (&gEfiMpServiceProtocolGuid, NULL, (VOID **)&mMpServicesProtocol); + + return UNIT_TEST_PASSED; +} + +/** + Basic Tests + + Validates that the DEBUG print blocks are returned as null terminated lines. + + @param[in] Context The test context + + @retval UNIT_TEST_PASSED The test passed. +**/ +STATIC +UNIT_TEST_STATUS +EFIAPI +TestCursorWrapping ( + IN UNIT_TEST_CONTEXT Context + ) +{ + BASIC_TEST_CONTEXT *Btc; + EFI_STATUS Status; + + Btc = (BASIC_TEST_CONTEXT *)Context; + + // First fill in the buffer + while (mLoggerInfo->LogCurrent + MESSAGE_ENTRY_SIZE_V2 (sizeof (ADVANCED_LOGGER_MESSAGE_ENTRY_V2), sizeof (ADV_TIME_TEST_STR)) < mMaxAddress) { + AdvancedLoggerWrite (DEBUG_ERROR, ADV_TIME_TEST_STR, sizeof (ADV_TIME_TEST_STR)); + } + + // This is the last logging that should push the buffer over the edge + AdvancedLoggerWrite (DEBUG_ERROR, ADV_WRAP_TEST_STR, sizeof (ADV_WRAP_TEST_STR)); + + Status = AdvancedLoggerAccessLibGetNextFormattedLine (&mMessageEntry); + + UT_ASSERT_STATUS_EQUAL (mLoggerInfo->LogCurrent - mLoggerInfo->LogBuffer, MESSAGE_ENTRY_SIZE_V2 (sizeof (ADVANCED_LOGGER_MESSAGE_ENTRY_V2), sizeof (ADV_WRAP_TEST_STR))); + UT_ASSERT_STATUS_EQUAL (Status, Btc->ExpectedStatus); + UT_ASSERT_NOT_NULL (mMessageEntry.Message); + UT_LOG_INFO ("\nReturn Length=%d\n", mMessageEntry.MessageLen); + UT_LOG_INFO ("\n = %a =\n", mMessageEntry.Message); + UT_LOG_INFO ("\nExpected Length=%d\n", AsciiStrLen (Btc->ExpectedLine)); + UT_LOG_INFO ("\n = %a =\n", Btc->ExpectedLine); + + if (mMessageEntry.MessageLen != AsciiStrLen (Btc->ExpectedLine)) { + DUMP_HEX (DEBUG_ERROR, 0, mMessageEntry.Message, mMessageEntry.MessageLen, "Actual - "); + DUMP_HEX (DEBUG_ERROR, 0, Btc->ExpectedLine, AsciiStrLen (Btc->ExpectedLine), "Expected - "); + } + + UT_ASSERT_EQUAL (mMessageEntry.MessageLen, AsciiStrLen (Btc->ExpectedLine)); + + Btc->MemoryToFree = mMessageEntry.Message; + + return UNIT_TEST_PASSED; +} + +/** + @brief This is the AP procedure that will be run on each AP. It will log a message + and then return. + + @param Buffer - A pointer to the buffer that was passed in to the AP startup code. +**/ +VOID +EFIAPI +ApProcedure ( + IN OUT VOID *Buffer + ) +{ + UINTN Index; + UINTN Size; + CHAR8 AsciiBuffer[8 + sizeof (ADV_WRAP_TEST_STR)]; + + // First figure out the current MP index + mMpServicesProtocol->WhoAmI (mMpServicesProtocol, &Index); + + // Then fill out the string buffer with the index + Size = AsciiSPrint (AsciiBuffer, sizeof (AsciiBuffer), "%08x%a", Index, ADV_WRAP_TEST_STR); + + // This is the last logging that should push the buffer over the edge + AdvancedLoggerWrite (DEBUG_ERROR, AsciiBuffer, Size); +} + +/** + Basic Tests in MP context. + + Validates that the DEBUG print blocks are returned as null terminated lines. + + This test is the same as TestCursorWrapping, but it uses the MP version of the + AdvancedLoggerAccessLibGetNextFormattedLine function. + + @param[in] Context The test context + + @retval UNIT_TEST_PASSED The test passed. +**/ +STATIC +UNIT_TEST_STATUS +EFIAPI +TestCursorWrappingMP ( + IN UNIT_TEST_CONTEXT Context + ) +{ + BASIC_TEST_CONTEXT *Btc; + EFI_STATUS Status; + UINTN Index; + UINTN StrIndex; + UINTN NumberOfProcessors; + UINTN EnabledProcessors; + UINT8 *TempCache = NULL; + UNIT_TEST_STATUS UtStatus; + UINTN PrefixSize; + CHAR8 *EndPointer; + + Btc = (BASIC_TEST_CONTEXT *)Context; + + // First fill in the buffer + while (mLoggerInfo->LogCurrent + MESSAGE_ENTRY_SIZE_V2 (sizeof (ADVANCED_LOGGER_MESSAGE_ENTRY_V2), sizeof (ADV_TIME_TEST_STR)) < mMaxAddress) { + AdvancedLoggerWrite (DEBUG_ERROR, ADV_TIME_TEST_STR, sizeof (ADV_TIME_TEST_STR)); + } + + if (mMpServicesProtocol == NULL) { + UtStatus = UNIT_TEST_ERROR_PREREQUISITE_NOT_MET; + goto Done; + } + + Status = mMpServicesProtocol->StartupAllAPs ( + mMpServicesProtocol, + (EFI_AP_PROCEDURE)ApProcedure, + FALSE, + NULL, + 0, + NULL, + NULL + ); + if (EFI_ERROR (Status)) { + UtStatus = UNIT_TEST_ERROR_TEST_FAILED; + goto Done; + } + + // BSP needs to run the procedure as well... + ApProcedure (NULL); + + Status = mMpServicesProtocol->GetNumberOfProcessors (mMpServicesProtocol, &NumberOfProcessors, &EnabledProcessors); + if (EFI_ERROR (Status)) { + UtStatus = UNIT_TEST_ERROR_TEST_FAILED; + goto Done; + } + + TempCache = AllocatePool (NumberOfProcessors * sizeof (UINT8)); + if (TempCache == NULL) { + UtStatus = UNIT_TEST_ERROR_TEST_FAILED; + goto Done; + } + + // Initialize the cache to 0xFF + SetMem (TempCache, NumberOfProcessors * sizeof (UINT8), 0xFF); + + for (Index = 0; Index < NumberOfProcessors; Index++) { + Status = AdvancedLoggerAccessLibGetNextFormattedLine (&mMessageEntry); + if (EFI_ERROR (Status)) { + UtStatus = UNIT_TEST_ERROR_TEST_FAILED; + goto Done; + } + + // HACKHACK: Bypass the potential print out from MpLib + if ((Index == 0) && (AsciiStrStr (mMessageEntry.Message, "5-Level Paging") != NULL)) { + Index--; + continue; + } + + UT_ASSERT_NOT_NULL (mMessageEntry.Message); + UT_LOG_INFO ("\nReturn Length=%d\n", mMessageEntry.MessageLen); + UT_LOG_INFO ("\n = %a =\n", mMessageEntry.Message); + UT_LOG_INFO ("\nExpected Length=%d\n", AsciiStrLen (Btc->ExpectedLine)); + UT_LOG_INFO ("\n = %a =\n", Btc->ExpectedLine); + + if (mMessageEntry.MessageLen != AsciiStrLen (Btc->ExpectedLine)) { + DUMP_HEX (DEBUG_ERROR, 0, mMessageEntry.Message, mMessageEntry.MessageLen, "Actual - "); + DUMP_HEX (DEBUG_ERROR, 0, Btc->ExpectedLine, AsciiStrLen (Btc->ExpectedLine), "Expected - "); + } + + UT_ASSERT_EQUAL (mMessageEntry.MessageLen, AsciiStrLen (Btc->ExpectedLine)); + + // The following verifies that the string content matches expectation and is NULL terminated, timestamp is not compared. + PrefixSize = AsciiStrLen (AdvMsgEntryPrefix[ADVANCED_LOGGER_PHASE_DXE]); + UT_ASSERT_MEM_EQUAL ( + &mMessageEntry.Message[ADV_TIME_STAMP_PREFIX_LEN], + AdvMsgEntryPrefix[ADVANCED_LOGGER_PHASE_DXE], + PrefixSize + ); + + // The following verifies that the string content is NULL terminated and matches expectation. + UT_ASSERT_MEM_EQUAL ( + &mMessageEntry.Message[ADV_TIME_STAMP_PREFIX_LEN + PrefixSize + 8], + ADV_WRAP_TEST_STR, + sizeof (ADV_WRAP_TEST_STR) + ); + + // Now check the index + EndPointer = &mMessageEntry.Message[ADV_TIME_STAMP_PREFIX_LEN + sizeof (ADV_WRAP_TEST_STR) + 8 - 1]; + Status = AsciiStrHexToUintnS ( + &mMessageEntry.Message[ADV_TIME_STAMP_PREFIX_LEN + sizeof (ADV_WRAP_TEST_STR) - 1], + &EndPointer, + &StrIndex + ); + if (EFI_ERROR (Status)) { + UtStatus = UNIT_TEST_ERROR_TEST_FAILED; + goto Done; + } + + if (StrIndex >= NumberOfProcessors) { + // Index is out of range + UtStatus = UNIT_TEST_ERROR_TEST_FAILED; + goto Done; + } + + if (TempCache[StrIndex] == 0) { + // Printed this index already + UtStatus = UNIT_TEST_ERROR_TEST_FAILED; + goto Done; + } else { + TempCache[StrIndex] = 0; + } + } + + if (!IsZeroBuffer (TempCache, NumberOfProcessors * sizeof (UINT8))) { + UtStatus = UNIT_TEST_ERROR_TEST_FAILED; + goto Done; + } + + UtStatus = UNIT_TEST_PASSED; + +Done: + if (TempCache != NULL) { + FreePool (TempCache); + } + + Btc->MemoryToFree = mMessageEntry.Message; + + return UtStatus; +} + +/// ================================================================================================ +/// ================================================================================================ +/// +/// TEST ENGINE +/// +/// ================================================================================================ +/// ================================================================================================ + +/** + DeviceIdTestAppEntry + + @param[in] ImageHandle The firmware allocated handle for the EFI image. + @param[in] SystemTable A pointer to the EFI System Table. + + @retval EFI_SUCCESS The entry point executed successfully. + @retval other Some error occurred when executing this entry point. + +**/ +EFI_STATUS +EFIAPI +AdvancedLoggerWrapperTestAppEntry ( + IN EFI_HANDLE ImageHandle, + IN EFI_SYSTEM_TABLE *SystemTable + ) +{ + UNIT_TEST_FRAMEWORK_HANDLE Fw; + UNIT_TEST_SUITE_HANDLE AdvLoggerWrapperTests; + EFI_STATUS Status; + + Fw = (UNIT_TEST_FRAMEWORK_HANDLE)NULL; + AsciiPrint ("%a v%a\n", UNIT_TEST_APP_NAME, UNIT_TEST_APP_VERSION); + DEBUG ((DEBUG_ERROR, "%a v%a\n", UNIT_TEST_APP_NAME, UNIT_TEST_APP_VERSION)); + + ZeroMem (&mMessageEntry, sizeof (mMessageEntry)); + + // + // Start setting up the test framework for running the tests. + // + Status = InitUnitTestFramework (&Fw, UNIT_TEST_APP_NAME, gEfiCallerBaseName, UNIT_TEST_APP_VERSION); + if (EFI_ERROR (Status)) { + AsciiPrint ("Failed in InitUnitTestFramework. Status = %r\n", Status); + goto EXIT; + } + + // + // Populate the DeviceId Library Test Suite. + // + Status = CreateUnitTestSuite (&AdvLoggerWrapperTests, Fw, "Validate Line parser returns valid data", "AdvancedLoggerWrapper.Test", NULL, NULL); + if (EFI_ERROR (Status)) { + AsciiPrint ("Failed in CreateUnitTestSuite for Line Parser Tests\n"); + Status = EFI_OUT_OF_RESOURCES; + goto EXIT; + } + + // Start with normal message entry tests + // -----------Suite------------Description-------Class---------Test Function-Pre---Clean-Context + AddTestCase (AdvLoggerWrapperTests, "Init", "SelfInit", InitializeInMemoryLog, NULL, NULL, NULL); + AddTestCase (AdvLoggerWrapperTests, "Basic check", "BasicCheck", TestCursorWrapping, NULL, CleanUpTestContext, &mTest00); + AddTestCase (AdvLoggerWrapperTests, "Basic check in MP Context", "BasicCheckInMP", TestCursorWrappingMP, NULL, CleanUpTestContext, &mTest01); + + // + // Execute the tests. + // + Status = RunAllTestSuites (Fw); + +EXIT: + if (Fw) { + FreeUnitTestFramework (Fw); + } + + return Status; +} diff --git a/AdvLoggerPkg/UnitTests/AdvancedLoggerWrapper/AdvancedLoggerWrapperTestApp.inf b/AdvLoggerPkg/UnitTests/AdvancedLoggerWrapper/AdvancedLoggerWrapperTestApp.inf new file mode 100644 index 0000000000..9467fc3e15 --- /dev/null +++ b/AdvLoggerPkg/UnitTests/AdvancedLoggerWrapper/AdvancedLoggerWrapperTestApp.inf @@ -0,0 +1,49 @@ +## @file +# AdvancedLoggerWrapperTestApp.inf +# +# Test application to verify the AdvancedLogger wrapping operations. +# +# Copyright (C) Microsoft Corporation. All rights reserved. +# SPDX-License-Identifier: BSD-2-Clause-Patent +# +## + +[Defines] + INF_VERSION = 1.26 + BASE_NAME = AdvancedLoggerWrapperTestApp + FILE_GUID = F4CFDDDD-AD19-457F-B1C0-79229D265593 + MODULE_TYPE = UEFI_APPLICATION + VERSION_STRING = 1.0 + ENTRY_POINT = AdvancedLoggerWrapperTestAppEntry + +# +# The following information is for reference only and not required by the build tools. +# +# VALID_ARCHITECTURES = IA32 X64 AARCH64 +# + +[Sources] + AdvancedLoggerWrapperTestApp.c + +[Packages] + MdePkg/MdePkg.dec + AdvLoggerPkg/AdvLoggerPkg.dec + +[Protocols] + gAdvancedLoggerProtocolGuid + gEfiMpServiceProtocolGuid + +[LibraryClasses] + AdvancedLoggerAccessLib + AdvancedLoggerLib + BaseLib + BaseMemoryLib + DebugLib + PrintLib + TimerLib + UefiApplicationEntryPoint + UefiLib + UnitTestLib + +[FeaturePcd] + gAdvLoggerPkgTokenSpaceGuid.PcdAdvancedLoggerAutoWrapEnable