From 267e27f6a64a80fe82e5ea9adef25edc71776ba3 Mon Sep 17 00:00:00 2001 From: kuqin12 <42554914+kuqin12@users.noreply.github.com> Date: Wed, 10 Jan 2024 14:06:18 -0800 Subject: [PATCH] Add prefix for advanced logger memory message entries (#388) # Preface Please ensure you have read the [contribution docs](https://github.com/microsoft/mu/blob/master/CONTRIBUTING.md) prior to submitting the pull request. In particular, [pull request guidelines](https://github.com/microsoft/mu/blob/master/CONTRIBUTING.md#pull-request-best-practices). ## Description This change introduces a new message entry structure, which contains extra information of log producer and can be used to differentiate the different boot phases, i.e. PEI, DXE, SMM, etc. Platforms that have multiple firmware entities can leverage this extra information to distinguish coalesced memory logging regions. The updated applications (UEFI shell app and host OS Python script) are also updated to support new message entry structure while maintaining the backwards compatibility. Resolves https://github.com/microsoft/mu_plus/issues/375. For each item, place an "x" in between `[` and `]` if true. Example: `[x]`. _(you can also check items in the GitHub UI)_ - [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, ... - [x] 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 change was tested on QEMU Q35 and verified that prefix are properly injected for DXE phase prints. ## Integration Instructions The log parsers are updated, thus platforms use the existing parser should pick up the latest tool from mu_plus. For platforms that carry their own implementation, they should add the proper support in their own implementation before picking up this change from mu_plus. --- .../DecodeUefiLog/DecodeUefiLog.py | 97 ++++++- AdvLoggerPkg/Include/AdvancedLoggerInternal.h | 44 +++- .../Include/Library/AdvancedLoggerAccessLib.h | 16 +- .../AdvancedLoggerAccessLib.c | 151 +++++++++-- .../AdvancedLoggerLib/AdvancedLoggerCommon.c | 36 +-- .../AdvancedLoggerLib/AdvancedLoggerCommon.h | 14 + .../BaseArm/AdvancedLoggerLib.c | 17 ++ .../DxeCore/AdvancedLoggerLib.c | 17 ++ .../MmCore/AdvancedLoggerLib.c | 17 ++ .../MmCoreArm/AdvancedLoggerLib.c | 17 ++ .../Pei64/AdvancedLoggerLib.c | 17 ++ .../PeiCore/AdvancedLoggerLib.c | 17 ++ .../Runtime/AdvancedLoggerLib.c | 17 ++ .../AdvancedLoggerLib/Sec/AdvancedLoggerLib.c | 17 ++ .../SmmCore/AdvancedLoggerLib.c | 17 ++ .../UnitTests/LineParser/LineParserTestApp.c | 241 +++++++++++++++++- 16 files changed, 680 insertions(+), 72 deletions(-) diff --git a/AdvLoggerPkg/Application/DecodeUefiLog/DecodeUefiLog.py b/AdvLoggerPkg/Application/DecodeUefiLog/DecodeUefiLog.py index 555f8ae6eb..b4f6c40bb3 100644 --- a/AdvLoggerPkg/Application/DecodeUefiLog/DecodeUefiLog.py +++ b/AdvLoggerPkg/Application/DecodeUefiLog/DecodeUefiLog.py @@ -186,6 +186,11 @@ class AdvLogParser (): V3_LOGGER_INFO_SIZE = 80 V3_LOGGER_INFO_VERSION = 3 + # V4 and V3 are the same definition, just an indicator for single firmware systems that + # starting from V4, all the message will have v2 message entry format. + V4_LOGGER_INFO_SIZE = V3_LOGGER_INFO_SIZE + V4_LOGGER_INFO_VERSION = 4 + # ---------------------------------------------------------------------- # # # @@ -199,6 +204,42 @@ class AdvLogParser (): # MESSAGE_ENTRY_SIZE = 18 MAX_MESSAGE_SIZE = 512 + # ---------------------------------------------------------------------- # + # + # + # typedef struct { + # UINT32 Signature; // Signature + # UINT8 MajorVersion; // Major version of advanced logger message structure + # UINT8 MinorVersion; // Minor version of advanced logger message structure + # UINT32 DebugLevel; // Debug Level + # UINT64 TimeStamp; // Time stamp + # UINT16 Phase; // Boot phase that produced this message entry + # UINT16 MessageLen; // Number of bytes in Message + # UINT16 MessageOffset; // Offset of Message from start of structure, + # // used to calculate the address of the Message + # CHAR8 MessageText[]; // Message Text + # } ADVANCED_LOGGER_MESSAGE_ENTRY_V2; + # + # + MESSAGE_ENTRY_SIZE_V2 = 24 + ADVANCED_LOGGER_PHASE_UNSPECIFIED = 0 + ADVANCED_LOGGER_PHASE_SEC = 1 + ADVANCED_LOGGER_PHASE_PEI = 2 + ADVANCED_LOGGER_PHASE_PEI64 = 3 + ADVANCED_LOGGER_PHASE_DXE = 4 + ADVANCED_LOGGER_PHASE_RUNTIME = 5 + ADVANCED_LOGGER_PHASE_MM_CORE = 6 + ADVANCED_LOGGER_PHASE_MM = 7 + ADVANCED_LOGGER_PHASE_SMM_CORE = 8 + ADVANCED_LOGGER_PHASE_SMM = 9 + ADVANCED_LOGGER_PHASE_TFA = 10 + ADVANCED_LOGGER_PHASE_CNT = 11 + PHASE_STRING_LIST = ["[UNSPECIFIED] ", "[SEC] ", "[PEI] ", "[PEI64] ", + "[DXE] ", "[RUNTIME] ", "[MM_CORE] ", "[MM] ", + "[SMM_CORE] ", "[SMM] ", "[TFA] "] + # + # ---------------------------------------------------------------------- # + # # # The dictionary entries for MessageLineEntry is based on the UEFI structure above. # @@ -296,7 +337,7 @@ def _InitializeLoggerInfo(self, InFile, StartLine): if InFile.tell() != (self.V1_LOGGER_INFO_SIZE): raise Exception('Error initializing logger info. AmountRead: %d' % InFile.tell()) - elif Version == self.V2_LOGGER_INFO_VERSION or Version == self.V3_LOGGER_INFO_VERSION: + elif Version == self.V2_LOGGER_INFO_VERSION or Version == self.V3_LOGGER_INFO_VERSION or Version == self.V4_LOGGER_INFO_VERSION: Size = self.V2_LOGGER_INFO_SIZE if Version == self.V2_LOGGER_INFO_VERSION else self.V3_LOGGER_INFO_SIZE BaseAddress = struct.unpack("=Q", InFile.read(8))[0] + Size LoggerInfo["LogBuffer"] = Size @@ -326,7 +367,7 @@ def _InitializeLoggerInfo(self, InFile, StartLine): InFile.read(1) # skip Pad2 field # If at v3, there will be 8 bytes for print level and pads, which we do not care. - if Version == self.V3_LOGGER_INFO_VERSION: + if Version == self.V3_LOGGER_INFO_VERSION or Version == self.V4_LOGGER_INFO_VERSION: InFile.read(4) InFile.read(4) @@ -360,12 +401,28 @@ def _ReadMessageEntry(self, LoggerInfo): MessageEntry = {} InFile = LoggerInfo["InFile"] - + EntryStart = InFile.tell() MessageEntry["Signature"] = InFile.read(4).decode('utf-8', 'replace') - MessageEntry["DebugLevel"] = struct.unpack("=I", InFile.read(4))[0] - MessageEntry["TimeStamp"] = struct.unpack("=Q", InFile.read(8))[0] - MessageEntry["MessageLen"] = struct.unpack("=H", InFile.read(2))[0] - MessageEntry["MessageText"] = InFile.read(MessageEntry["MessageLen"]).decode('utf-8', 'replace') + + if (MessageEntry["Signature"] == 'ALMS'): + MessageEntry["DebugLevel"] = struct.unpack("=I", InFile.read(4))[0] + MessageEntry["TimeStamp"] = struct.unpack("=Q", InFile.read(8))[0] + MessageEntry["MessageLen"] = struct.unpack("=H", InFile.read(2))[0] + MessageEntry["MessageText"] = InFile.read(MessageEntry["MessageLen"]).decode('utf-8', 'replace') + MessageEntry["Phase"] = self.ADVANCED_LOGGER_PHASE_UNSPECIFIED + elif (MessageEntry["Signature"] == 'ALM2'): + MessageEntry["MajorVersion"] = struct.unpack("=B", InFile.read(1))[0] + MessageEntry["MinorVersion"] = struct.unpack("=B", InFile.read(1))[0] + MessageEntry["DebugLevel"] = struct.unpack("=I", InFile.read(4))[0] + MessageEntry["TimeStamp"] = struct.unpack("=Q", InFile.read(8))[0] + MessageEntry["Phase"] = struct.unpack("=H", InFile.read(2))[0] + MessageEntry["MessageLen"] = struct.unpack("=H", InFile.read(2))[0] + MessageEntry["MessageOffset"] = struct.unpack("=H", InFile.read(2))[0] + # Offset is from the start of the structure, so we do that from the beginning of this file + InFile.seek(EntryStart + MessageEntry["MessageOffset"]) + MessageEntry["MessageText"] = InFile.read(MessageEntry["MessageLen"]).decode('utf-8', 'replace') + else: + raise Exception("Message Block has wrong signature at offset 0x%X" % InFile.tell()) Skip = InFile.tell() Norm = int((int((Skip + 7) / 8)) * 8) @@ -374,7 +431,10 @@ def _ReadMessageEntry(self, LoggerInfo): InFile.read(Skip) NextMessage = InFile.tell() - NextMessageLen = self.MESSAGE_ENTRY_SIZE + int(int((MessageEntry["MessageLen"] + 7) / 8) * 8) + if MessageEntry["Signature"] == 'ALMS': + NextMessageLen = self.MESSAGE_ENTRY_SIZE + int(int((MessageEntry["MessageLen"] + 7) / 8) * 8) + elif MessageEntry["Signature"] == 'ALM2': + NextMessageLen = MessageEntry["MessageOffset"] + int(int((MessageEntry["MessageLen"] + 7) / 8) * 8) NextMessage = NextMessage + NextMessageLen return (MessageEntry, NextMessage) @@ -401,14 +461,15 @@ def _GetNextMessageBlock(self, LoggerInfo): (MessageEntry, NextMessage) = self._ReadMessageEntry(LoggerInfo) - if MessageEntry["Signature"] != 'ALMS': - print("Log signature was incorrect. Should be 'ALMS', was '%s'" % MessageEntry["Signature"]) + if MessageEntry["Signature"] != 'ALMS' and MessageEntry["Signature"] != 'ALM2': + print("Log signature was incorrect. Should be either 'ALMS' or 'ALM2', was '%s'" % MessageEntry["Signature"]) raise Exception("Message Block has wrong signature at offset 0x%X" % InFile.tell()) MessageBlock["Message"] = MessageEntry["MessageText"] MessageBlock["DebugLevel"] = MessageEntry["DebugLevel"] MessageBlock["MessageLen"] = MessageEntry["MessageLen"] MessageBlock["TimeStamp"] = MessageEntry["TimeStamp"] + MessageBlock["Phase"] = MessageEntry["Phase"] return (self.SUCCESS, MessageBlock) @@ -476,6 +537,7 @@ def _GetNextFormattedLine(self, AccessMessageLineEntry, LoggerInfo): AccessMessageLineEntry["ResidualChar"] = AccessMessageBlock["Message"] AccessMessageLineEntry["TimeStamp"] = AccessMessageBlock["TimeStamp"] AccessMessageLineEntry["DebugLevel"] = AccessMessageBlock["DebugLevel"] + AccessMessageLineEntry["Phase"] = AccessMessageBlock["Phase"] return (Status, AccessMessageLineEntry) @@ -515,6 +577,18 @@ def _GetTimeStamp(self, Ticks, Frequency, BaseTime): return Timestamp + # + # Get the formatted phase string + # + def _GetPhaseString(self, Phase): + if Phase >= self.ADVANCED_LOGGER_PHASE_CNT: + PhaseString = f"[{Phase:04}] " + elif Phase <= self.ADVANCED_LOGGER_PHASE_UNSPECIFIED: + PhaseString = "" + else: + PhaseString = self.PHASE_STRING_LIST[Phase] + return PhaseString + # # Get all of the formated message lines # @@ -533,7 +607,8 @@ def _GetLines(self, lines, LoggerInfo): if CurrentLine >= StartLine: Ticks = MessageLine["TimeStamp"] - NewLine = self._GetTimeStamp(Ticks, LoggerInfo["Frequency"], LoggerInfo["BaseTime"]) + MessageLine["Message"].rstrip("\r\n") + PhaseString = self._GetPhaseString(MessageLine["Phase"]) + NewLine = self._GetTimeStamp(Ticks, LoggerInfo["Frequency"], LoggerInfo["BaseTime"]) + PhaseString + MessageLine["Message"].rstrip("\r\n") lines.append(NewLine + '\n') CurrentLine += 1 diff --git a/AdvLoggerPkg/Include/AdvancedLoggerInternal.h b/AdvLoggerPkg/Include/AdvancedLoggerInternal.h index 6a351a507e..a68aa87089 100644 --- a/AdvLoggerPkg/Include/AdvancedLoggerInternal.h +++ b/AdvLoggerPkg/Include/AdvancedLoggerInternal.h @@ -11,11 +11,26 @@ #ifndef __ADVANCED_LOGGER_INTERNAL_H__ #define __ADVANCED_LOGGER_INTERNAL_H__ -#define ADVANCED_LOGGER_SIGNATURE SIGNATURE_32('A','L','O','G') -#define ADVANCED_LOGGER_HW_LVL_VER 3 +#define ADVANCED_LOGGER_SIGNATURE SIGNATURE_32('A','L','O','G') +#define ADVANCED_LOGGER_HW_LVL_VER 4 +#define ADVANCED_LOGGER_MSG_MAJ_VER 2 +#define ADVANCED_LOGGER_MSG_MIN_VER 0 #define ADVANCED_LOGGER_VERSION ADVANCED_LOGGER_HW_LVL_VER +#define ADVANCED_LOGGER_PHASE_UNSPECIFIED 0 +#define ADVANCED_LOGGER_PHASE_SEC 1 +#define ADVANCED_LOGGER_PHASE_PEI 2 +#define ADVANCED_LOGGER_PHASE_PEI64 3 +#define ADVANCED_LOGGER_PHASE_DXE 4 +#define ADVANCED_LOGGER_PHASE_RUNTIME 5 +#define ADVANCED_LOGGER_PHASE_MM_CORE 6 +#define ADVANCED_LOGGER_PHASE_MM 7 +#define ADVANCED_LOGGER_PHASE_SMM_CORE 8 +#define ADVANCED_LOGGER_PHASE_SMM 9 +#define ADVANCED_LOGGER_PHASE_TFA 10 +#define ADVANCED_LOGGER_PHASE_CNT 11 + // // These Pcds are used to carve out a PEI memory buffer from the temporary RAM. // @@ -59,13 +74,30 @@ typedef struct { CHAR8 MessageText[]; // Message Text } ADVANCED_LOGGER_MESSAGE_ENTRY; -#define MESSAGE_ENTRY_SIZE(LenOfMessage) (ALIGN_VALUE(sizeof(ADVANCED_LOGGER_MESSAGE_ENTRY) + LenOfMessage ,8)) +typedef struct { + UINT32 Signature; // Signature + UINT8 MajorVersion; // Major version of advanced logger message structure + UINT8 MinorVersion; // Minor version of advanced logger message structure + UINT32 DebugLevel; // Debug Level + UINT64 TimeStamp; // Time stamp + UINT16 Phase; // Boot phase that produced this message entry + UINT16 MessageLen; // Number of bytes in Message + UINT16 MessageOffset; // Offset of Message from start of structure, + // used to calculate the address of the Message + CHAR8 MessageText[]; // Message Text +} ADVANCED_LOGGER_MESSAGE_ENTRY_V2; + +#define MESSAGE_ENTRY_SIZE(LenOfMessage) (ALIGN_VALUE(sizeof(ADVANCED_LOGGER_MESSAGE_ENTRY) + LenOfMessage ,8)) +#define MESSAGE_ENTRY_SIZE_V2(LenOfEntry, LenOfMessage) (ALIGN_VALUE(LenOfEntry + LenOfMessage ,8)) -#define NEXT_LOG_ENTRY(LogEntry) ((ADVANCED_LOGGER_MESSAGE_ENTRY *) ((UINTN) LogEntry + MESSAGE_ENTRY_SIZE(LogEntry->MessageLen))) +#define NEXT_LOG_ENTRY(LogEntry) ((ADVANCED_LOGGER_MESSAGE_ENTRY *)((UINTN)LogEntry + MESSAGE_ENTRY_SIZE(LogEntry->MessageLen))) +#define NEXT_LOG_ENTRY_V2(LogEntryV2) ((ADVANCED_LOGGER_MESSAGE_ENTRY_V2 *)((UINTN)LogEntryV2 + MESSAGE_ENTRY_SIZE_V2(LogEntryV2->MessageOffset, LogEntryV2->MessageLen))) -#define MESSAGE_ENTRY_SIGNATURE SIGNATURE_32('A','L','M','S') +#define MESSAGE_ENTRY_SIGNATURE SIGNATURE_32('A','L','M','S') +#define MESSAGE_ENTRY_SIGNATURE_V2 SIGNATURE_32('A','L','M','2') -#define MESSAGE_ENTRY_FROM_MSG(a) BASE_CR (a, ADVANCED_LOGGER_MESSAGE_ENTRY, MessageText) +#define MESSAGE_ENTRY_FROM_MSG(a) BASE_CR (a, ADVANCED_LOGGER_MESSAGE_ENTRY, MessageText) +#define MESSAGE_ENTRY_FROM_MSG_V2(a, offset) ((UINTN)a - offset) // // Insure the size of is a multiple of 8 bytes diff --git a/AdvLoggerPkg/Include/Library/AdvancedLoggerAccessLib.h b/AdvLoggerPkg/Include/Library/AdvancedLoggerAccessLib.h index dbe31ed71e..f563ae1e4a 100644 --- a/AdvLoggerPkg/Include/Library/AdvancedLoggerAccessLib.h +++ b/AdvLoggerPkg/Include/Library/AdvancedLoggerAccessLib.h @@ -41,13 +41,14 @@ MAX MESSAGE size. typedef struct { // Message is IN/OUT. On the first input, it must be NULL. On subsequent // calls, the previously returned pointer to know where to get the next - // message. Message is a pointer into the physical memory buffer, and it NOT + // message. Message is a pointer into the physical memory buffer, and is NOT // properly terminated. CONST CHAR8 *Message; // NULL (first), Pointer to Current Message Text UINT32 DebugLevel; // DEBUG Message Level UINT16 MessageLen; // Number of bytes in Message - UINT16 Reserved; + UINT16 Phase; // Boot phase that produced this message entry UINT64 TimeStamp; // Time stamp + UINT16 MessageOffset; // Offset of Message in the physical memory buffer } ADVANCED_LOGGER_ACCESS_MESSAGE_BLOCK_ENTRY; typedef struct { @@ -56,11 +57,12 @@ typedef struct { // formatting a line. Message will point to a properly NULL terminated ASCII STRING. // BlockEntry is used to manage the current place in the physical memory buffer. - CHAR8 *Message; // Pointer to Message Text - UINT32 DebugLevel; // DEBUG Message Level - UINT16 MessageLen; // Number of bytes in Message - UINT16 Reserved; - UINT64 TimeStamp; // Time stamp + CHAR8 *Message; // Pointer to Message Text + UINT32 DebugLevel; // DEBUG Message Level + UINT16 MessageLen; // Number of bytes in Message + UINT16 Phase; // Boot phase that produced this message entry + UINT64 TimeStamp; // Time stamp + UINT16 MessageOffset; // Offset of Message in the physical memory buffer // The following are private members for GetNextBlock. Initialize these // members to NULL and 0 respectively. diff --git a/AdvLoggerPkg/Library/AdvancedLoggerAccessLib/AdvancedLoggerAccessLib.c b/AdvLoggerPkg/Library/AdvancedLoggerAccessLib/AdvancedLoggerAccessLib.c index c1de35585e..349fd18bb3 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerAccessLib/AdvancedLoggerAccessLib.c +++ b/AdvLoggerPkg/Library/AdvancedLoggerAccessLib/AdvancedLoggerAccessLib.c @@ -22,13 +22,28 @@ #include #include -STATIC ADVANCED_LOGGER_INFO *mLoggerInfo = NULL; -STATIC ADVANCED_LOGGER_MESSAGE_ENTRY *mLowAddress = NULL; -STATIC ADVANCED_LOGGER_MESSAGE_ENTRY *mHighAddress = NULL; -STATIC UINT16 mMaxMessageSize = ADVANCED_LOGGER_MAX_MESSAGE_SIZE; +STATIC ADVANCED_LOGGER_INFO *mLoggerInfo = NULL; +STATIC EFI_PHYSICAL_ADDRESS mLowAddress = 0; +STATIC EFI_PHYSICAL_ADDRESS mHighAddress = 0; +STATIC UINT16 mMaxMessageSize = ADVANCED_LOGGER_MAX_MESSAGE_SIZE; +CONST CHAR8 *AdvMsgEntryPrefix[ADVANCED_LOGGER_PHASE_CNT] = { + "[UNSPECIFIED] ", + "[SEC] ", + "[PEI] ", + "[PEI64] ", + "[DXE] ", + "[RUNTIME] ", + "[MM_CORE] ", + "[MM] ", + "[SMM_CORE] ", + "[SMM] ", + "[TFA] ", +}; #define ADV_TIME_STAMP_FORMAT "%2.2d:%2.2d:%2.2d.%3.3d : " #define ADV_TIME_STAMP_RESULT "hh:mm:ss:ttt : " +#define ADV_PHASE_ERR_FORMAT "[%04X] " +#define ADV_PHASE_MAX_SIZE 32 /** @@ -85,6 +100,42 @@ FormatTimeStamp ( return (UINT16)TimeStampLen; } +/** + FormatPhasePrefix + + Adds a phase indicator to the message being returned. If phase is recognized and specified, + returns the phase prefix in from the AdvMsgEntryPrefix, otherwise raw phase value is returned. + + @param MessageBuffer + @param MessageBufferSize + @param Phase + + @retval Number of characters printed +*/ +STATIC +UINT16 +FormatPhasePrefix ( + IN CHAR8 *MessageBuffer, + IN UINTN MessageBufferSize, + IN UINT16 Phase + ) +{ + UINTN PhaseStringLen; + + if (Phase == ADVANCED_LOGGER_PHASE_UNSPECIFIED) { + // This might be a legacy message + PhaseStringLen = AsciiSPrint (MessageBuffer, MessageBufferSize, ""); + } else if (Phase < ADVANCED_LOGGER_PHASE_CNT) { + // Normal message we recognize + PhaseStringLen = AsciiSPrint (MessageBuffer, MessageBufferSize, AdvMsgEntryPrefix[Phase]); + } else { + // Unrecognized phase, just print the raw value + PhaseStringLen = AsciiSPrint (MessageBuffer, MessageBufferSize, ADV_PHASE_ERR_FORMAT, Phase); + } + + return (UINT16)PhaseStringLen; +} + /** Get Next Message Block. @@ -112,7 +163,8 @@ AdvancedLoggerAccessLibGetNextMessageBlock ( IN ADVANCED_LOGGER_ACCESS_MESSAGE_BLOCK_ENTRY *BlockEntry ) { - ADVANCED_LOGGER_MESSAGE_ENTRY *LogEntry; + ADVANCED_LOGGER_MESSAGE_ENTRY *LogEntry = NULL; + ADVANCED_LOGGER_MESSAGE_ENTRY_V2 *LogEntryV2 = NULL; if (mLoggerInfo == NULL) { return EFI_NOT_STARTED; @@ -128,22 +180,44 @@ AdvancedLoggerAccessLibGetNextMessageBlock ( if (BlockEntry->Message == NULL) { LogEntry = (ADVANCED_LOGGER_MESSAGE_ENTRY *)PTR_FROM_PA (mLoggerInfo->LogBuffer); + if (LogEntry->Signature == MESSAGE_ENTRY_SIGNATURE_V2) { + // This is actually a v2 entry. + LogEntryV2 = (ADVANCED_LOGGER_MESSAGE_ENTRY_V2 *)LogEntry; + } } else { LogEntry = (ADVANCED_LOGGER_MESSAGE_ENTRY *)MESSAGE_ENTRY_FROM_MSG (BlockEntry->Message); if (LogEntry->Signature != MESSAGE_ENTRY_SIGNATURE) { - DEBUG ((DEBUG_ERROR, "Resume LogEntry invalid signature at %p\n", LogEntry)); - DUMP_HEX (DEBUG_INFO, 0, (CHAR8 *)LogEntry - 128, 256, ""); - return EFI_INVALID_PARAMETER; + // If this is not a v1 entry, this might be a v2 entry. + LogEntryV2 = (ADVANCED_LOGGER_MESSAGE_ENTRY_V2 *)MESSAGE_ENTRY_FROM_MSG_V2 (BlockEntry->Message, BlockEntry->MessageOffset); + if (LogEntryV2->Signature != MESSAGE_ENTRY_SIGNATURE_V2) { + DEBUG ((DEBUG_ERROR, "Resume LogEntry invalid signature at %p or %p\n", LogEntry, LogEntryV2)); + DUMP_HEX (DEBUG_INFO, 0, (CHAR8 *)LogEntry - 128, 256, ""); + return EFI_INVALID_PARAMETER; + } + } + + if (LogEntryV2) { + LogEntryV2 = NEXT_LOG_ENTRY_V2 (LogEntryV2); + } else { + LogEntry = NEXT_LOG_ENTRY (LogEntry); } + } - LogEntry = NEXT_LOG_ENTRY (LogEntry); + // At this point, if LogEntryV2 is not NULL, it points to the next entry to be read. + // Otherwise LogEntry will contain the next entry. So we simplify the logic by only + // using LogEntry and overwriting it to use the LogEntryV2 data as necessary. However, + // note that regardless of how we inherit the pointer it has the possibility of + // pointing to a different version of structure than the one we just looked at. So + // we need to validate the structure before we can use it. + if (LogEntryV2 != NULL) { + LogEntry = (ADVANCED_LOGGER_MESSAGE_ENTRY *)LogEntryV2; } // Validate that LogEntry points within the proper Memory Log region // in memory log buffer if ((LogEntry != (ADVANCED_LOGGER_MESSAGE_ENTRY *)ALIGN_POINTER (LogEntry, 8)) || // Insure pointer is on boundary - (LogEntry < mLowAddress) || // and within the log region - (LogEntry > mHighAddress)) + (PA_FROM_PTR (LogEntry) < mLowAddress) || // and within the log region + (PA_FROM_PTR (LogEntry) > mHighAddress)) { DEBUG ((DEBUG_ERROR, "Invalid Address for LogEntry %p. Low=%p, High=%p\n", LogEntry, mLowAddress, mHighAddress)); return EFI_INVALID_PARAMETER; @@ -153,18 +227,27 @@ AdvancedLoggerAccessLibGetNextMessageBlock ( return EFI_END_OF_FILE; } - if (LogEntry->Signature != MESSAGE_ENTRY_SIGNATURE) { + if (LogEntry->Signature == MESSAGE_ENTRY_SIGNATURE) { + BlockEntry->TimeStamp = LogEntry->TimeStamp; + BlockEntry->DebugLevel = LogEntry->DebugLevel; + BlockEntry->Message = LogEntry->MessageText; + BlockEntry->MessageLen = LogEntry->MessageLen; + BlockEntry->Phase = ADVANCED_LOGGER_PHASE_UNSPECIFIED; + } else if (LogEntry->Signature == MESSAGE_ENTRY_SIGNATURE_V2) { + LogEntryV2 = (ADVANCED_LOGGER_MESSAGE_ENTRY_V2 *)LogEntry; + BlockEntry->TimeStamp = LogEntryV2->TimeStamp; + BlockEntry->DebugLevel = LogEntryV2->DebugLevel; + BlockEntry->Message = LogEntryV2->MessageText; + BlockEntry->MessageLen = LogEntryV2->MessageLen; + BlockEntry->MessageOffset = LogEntryV2->MessageOffset; + BlockEntry->Phase = LogEntryV2->Phase; + } else { DEBUG ((DEBUG_ERROR, "Next LogEntry invalid signature at %p, Last=%p\n", LogEntry, BlockEntry->Message)); DUMP_HEX (DEBUG_INFO, 0, (CHAR8 *)BlockEntry->Message - 128, 256, ""); DUMP_HEX (DEBUG_INFO, 0, (CHAR8 *)LogEntry - 128, 256, ""); return EFI_COMPROMISED_DATA; } - BlockEntry->TimeStamp = LogEntry->TimeStamp; - BlockEntry->DebugLevel = LogEntry->DebugLevel; - BlockEntry->Message = LogEntry->MessageText; - BlockEntry->MessageLen = LogEntry->MessageLen; - return EFI_SUCCESS; } @@ -201,7 +284,10 @@ AdvancedLoggerAccessLibGetNextFormattedLine ( EFI_STATUS Status; CHAR8 *TargetPtr; UINT16 TargetLen; - CHAR8 TimeStampString[] = { ADV_TIME_STAMP_RESULT }; + UINT16 PhaseStringLen; + UINT16 CurrPhaseStringLen; + CHAR8 TimeStampString[] = { ADV_TIME_STAMP_RESULT }; + CHAR8 PhaseString[ADV_PHASE_MAX_SIZE] = { 0 }; if (LineEntry == NULL) { return EFI_INVALID_PARAMETER; @@ -212,7 +298,7 @@ AdvancedLoggerAccessLibGetNextFormattedLine ( // reuse the previous LineBuffer // if (LineEntry->Message == NULL) { - LineBuffer = AllocatePool (mMaxMessageSize+sizeof (TimeStampString)); + LineBuffer = AllocatePool (mMaxMessageSize + sizeof (TimeStampString) + ADV_PHASE_MAX_SIZE); if (LineBuffer == NULL) { return EFI_OUT_OF_RESOURCES; } @@ -227,13 +313,15 @@ AdvancedLoggerAccessLibGetNextFormattedLine ( // the first '\n' are left in the ResidualMemoryBuffer for use on the next call to // GetNextLine. - // In case this is a restart of the same Message, initialize the time stamp. + // In case this is a restart of the same Message, initialize the time stamp and prefix. if (LineEntry->BlockEntry.Message != NULL) { FormatTimeStamp (TimeStampString, sizeof (TimeStampString), LineEntry->BlockEntry.TimeStamp); CopyMem (LineBuffer, TimeStampString, sizeof (TimeStampString) - sizeof (CHAR8)); + PhaseStringLen = FormatPhasePrefix (PhaseString, sizeof (PhaseString), LineEntry->BlockEntry.Phase); + CopyMem (LineBuffer + sizeof (TimeStampString) - sizeof (CHAR8), PhaseString, PhaseStringLen); } - TargetPtr = &LineBuffer[sizeof (TimeStampString) - sizeof (CHAR8)]; + TargetPtr = &LineBuffer[sizeof (TimeStampString) - sizeof (CHAR8) + PhaseStringLen]; TargetLen = 0; Status = EFI_SUCCESS; @@ -289,13 +377,22 @@ AdvancedLoggerAccessLibGetNextFormattedLine ( LineEntry->ResidualLen = LineEntry->BlockEntry.MessageLen; FormatTimeStamp (TimeStampString, sizeof (TimeStampString), LineEntry->BlockEntry.TimeStamp); CopyMem (LineBuffer, TimeStampString, sizeof (TimeStampString) - sizeof (CHAR8)); + CurrPhaseStringLen = FormatPhasePrefix (PhaseString, sizeof (PhaseString), LineEntry->BlockEntry.Phase); + if (PhaseStringLen != CurrPhaseStringLen) { + // Adjust the TargetPtr to point to the end of the PhaseString + PhaseStringLen = CurrPhaseStringLen; + TargetPtr = &LineBuffer[sizeof (TimeStampString) - sizeof (CHAR8) + PhaseStringLen]; + } + + CopyMem (LineBuffer + sizeof (TimeStampString) - sizeof (CHAR8), PhaseString, PhaseStringLen); } } while (!EFI_ERROR (Status)); if (!EFI_ERROR (Status)) { - LineEntry->MessageLen = TargetLen + sizeof (TimeStampString) - sizeof (CHAR8); + LineEntry->MessageLen = TargetLen + sizeof (TimeStampString) - sizeof (CHAR8) + PhaseStringLen; LineEntry->TimeStamp = LineEntry->BlockEntry.TimeStamp; LineEntry->DebugLevel = LineEntry->BlockEntry.DebugLevel; + LineEntry->Phase = LineEntry->BlockEntry.Phase; } return Status; @@ -340,8 +437,8 @@ AdvancedLoggerAccessLibUnitTestInitialize ( if (!EFI_ERROR (Status)) { mLoggerInfo = LOGGER_INFO_FROM_PROTOCOL (LoggerProtocol); - mLowAddress = (ADVANCED_LOGGER_MESSAGE_ENTRY *)PTR_FROM_PA (mLoggerInfo->LogBuffer); - mHighAddress = (ADVANCED_LOGGER_MESSAGE_ENTRY *)PTR_FROM_PA (mLoggerInfo->LogBuffer + mLoggerInfo->LogBufferSize); + mLowAddress = mLoggerInfo->LogBuffer; + mHighAddress = mLoggerInfo->LogBuffer + mLoggerInfo->LogBufferSize; } return Status; @@ -367,12 +464,12 @@ AdvancedLoggerAccessLibConstructor ( ); if (!EFI_ERROR (Status)) { mLoggerInfo = LOGGER_INFO_FROM_PROTOCOL (LoggerProtocol); - mLowAddress = (ADVANCED_LOGGER_MESSAGE_ENTRY *)PTR_FROM_PA (mLoggerInfo->LogBuffer); - mHighAddress = (ADVANCED_LOGGER_MESSAGE_ENTRY *)PTR_FROM_PA (mLoggerInfo->LogBuffer + mLoggerInfo->LogBufferSize); + mLowAddress = mLoggerInfo->LogBuffer; + mHighAddress = mLoggerInfo->LogBuffer + mLoggerInfo->LogBufferSize; // Leave this debug message as ERROR. - DEBUG ((DEBUG_ERROR, "Advanced Logger Info = %p, Max = %p\n", mLoggerInfo, mHighAddress)); + DEBUG ((DEBUG_ERROR, "Advanced Logger Info = %p, Min = %p, Max = %p\n", mLoggerInfo, mLowAddress, mHighAddress)); } // Don't fail module load... diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/AdvancedLoggerCommon.c b/AdvLoggerPkg/Library/AdvancedLoggerLib/AdvancedLoggerCommon.c index 40a829a9fa..bfd601c923 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/AdvancedLoggerCommon.c +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/AdvancedLoggerCommon.c @@ -40,16 +40,16 @@ AdvancedLoggerMemoryLoggerWrite ( IN UINTN NumberOfBytes ) { - ADVANCED_LOGGER_INFO *LoggerInfo; - EFI_PHYSICAL_ADDRESS CurrentBuffer; - EFI_PHYSICAL_ADDRESS NewBuffer; - EFI_PHYSICAL_ADDRESS OldValue; - UINT32 OldSize; - UINT32 NewSize; - UINT32 CurrentSize; - UINTN EntrySize; - UINTN UsedSize; - ADVANCED_LOGGER_MESSAGE_ENTRY *Entry; + ADVANCED_LOGGER_INFO *LoggerInfo; + EFI_PHYSICAL_ADDRESS CurrentBuffer; + EFI_PHYSICAL_ADDRESS NewBuffer; + EFI_PHYSICAL_ADDRESS OldValue; + UINT32 OldSize; + UINT32 NewSize; + UINT32 CurrentSize; + UINTN EntrySize; + UINTN UsedSize; + ADVANCED_LOGGER_MESSAGE_ENTRY_V2 *Entry; if ((NumberOfBytes == 0) || (Buffer == NULL)) { return NULL; @@ -62,7 +62,7 @@ AdvancedLoggerMemoryLoggerWrite ( LoggerInfo = AdvancedLoggerGetLoggerInfo (); if (LoggerInfo != NULL) { - EntrySize = MESSAGE_ENTRY_SIZE (NumberOfBytes); + EntrySize = MESSAGE_ENTRY_SIZE_V2 (OFFSET_OF (ADVANCED_LOGGER_MESSAGE_ENTRY_V2, MessageText), NumberOfBytes); do { CurrentBuffer = LoggerInfo->LogCurrent; UsedSize = (UINTN)(CurrentBuffer - LoggerInfo->LogBuffer); @@ -93,15 +93,19 @@ AdvancedLoggerMemoryLoggerWrite ( ); } while (OldValue != CurrentBuffer); - Entry = (ADVANCED_LOGGER_MESSAGE_ENTRY *)PTR_FROM_PA (CurrentBuffer); - Entry->TimeStamp = GetPerformanceCounter (); // AdvancedLoggerGetTimeStamp(); + Entry = (ADVANCED_LOGGER_MESSAGE_ENTRY_V2 *)PTR_FROM_PA (CurrentBuffer); + Entry->MajorVersion = ADVANCED_LOGGER_MSG_MAJ_VER; + Entry->MinorVersion = ADVANCED_LOGGER_MSG_MIN_VER; + Entry->TimeStamp = GetPerformanceCounter (); // AdvancedLoggerGetTimeStamp(); + Entry->Phase = AdvancedLoggerGetPhase (); // DebugLevel is defined as a UINTN, so it is 32 bits in PEI and 64 bits in DXE. // However, the DEBUG_* values and the PcdFixedDebugPrintErrorLevel are only 32 bits. - Entry->DebugLevel = (UINT32)DebugLevel; - Entry->MessageLen = (UINT16)NumberOfBytes; + Entry->DebugLevel = (UINT32)DebugLevel; + Entry->MessageOffset = OFFSET_OF (ADVANCED_LOGGER_MESSAGE_ENTRY_V2, MessageText); + Entry->MessageLen = (UINT16)NumberOfBytes; CopyMem (Entry->MessageText, Buffer, NumberOfBytes); - Entry->Signature = MESSAGE_ENTRY_SIGNATURE; + Entry->Signature = MESSAGE_ENTRY_SIGNATURE_V2; } return LoggerInfo; diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/AdvancedLoggerCommon.h b/AdvLoggerPkg/Library/AdvancedLoggerLib/AdvancedLoggerCommon.h index 9c4049c1af..49f9e5939f 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/AdvancedLoggerCommon.h +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/AdvancedLoggerCommon.h @@ -44,4 +44,18 @@ AdvancedLoggerGetLoggerInfo ( VOID ); +/** + Helper function to return the log phase for each message. + + This function is intended to be used to distinguish between + various types of modules. + + @return Phase of current advanced logger instance. +**/ +UINT16 +EFIAPI +AdvancedLoggerGetPhase ( + VOID + ); + #endif // __ADVANCED_LOGGER_COMMON_H__ diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/BaseArm/AdvancedLoggerLib.c b/AdvLoggerPkg/Library/AdvancedLoggerLib/BaseArm/AdvancedLoggerLib.c index 0f95bf10b0..9c35a147ad 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/BaseArm/AdvancedLoggerLib.c +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/BaseArm/AdvancedLoggerLib.c @@ -116,3 +116,20 @@ AdvancedLoggerGetLoggerInfo ( return mLoggerInfo; } + +/** + Helper function to return the log phase for each message. + + This function is intended to be used to distinguish between + various types of modules. + + @return Phase of current advanced logger instance. +**/ +UINT16 +EFIAPI +AdvancedLoggerGetPhase ( + VOID + ) +{ + return ADVANCED_LOGGER_PHASE_MM; +} diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/DxeCore/AdvancedLoggerLib.c b/AdvLoggerPkg/Library/AdvancedLoggerLib/DxeCore/AdvancedLoggerLib.c index bbfcf98bda..1f76d905b0 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/DxeCore/AdvancedLoggerLib.c +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/DxeCore/AdvancedLoggerLib.c @@ -166,6 +166,23 @@ AdvancedLoggerGetLoggerInfo ( return mLoggerInfo; } +/** + Helper function to return the log phase for each message. + + This function is intended to be used to distinguish between + various types of modules. + + @return Phase of current advanced logger instance. +**/ +UINT16 +EFIAPI +AdvancedLoggerGetPhase ( + VOID + ) +{ + return ADVANCED_LOGGER_PHASE_DXE; +} + /** OnRuntimeArchNotification diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/MmCore/AdvancedLoggerLib.c b/AdvLoggerPkg/Library/AdvancedLoggerLib/MmCore/AdvancedLoggerLib.c index 024f7ea7a7..5b3f86da1d 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/MmCore/AdvancedLoggerLib.c +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/MmCore/AdvancedLoggerLib.c @@ -121,6 +121,23 @@ AdvancedLoggerGetLoggerInfo ( return mLoggerInfo; } +/** + Helper function to return the log phase for each message. + + This function is intended to be used to distinguish between + various types of modules. + + @return Phase of current advanced logger instance. +**/ +UINT16 +EFIAPI +AdvancedLoggerGetPhase ( + VOID + ) +{ + return ADVANCED_LOGGER_PHASE_MM_CORE; +} + /** The constructor function initializes Logger Information pointer to ensure that the pointer is initialized when MM is loaded, either by the constructor, or the first DEBUG message. diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/MmCoreArm/AdvancedLoggerLib.c b/AdvLoggerPkg/Library/AdvancedLoggerLib/MmCoreArm/AdvancedLoggerLib.c index c381c298f6..97cd71f2ee 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/MmCoreArm/AdvancedLoggerLib.c +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/MmCoreArm/AdvancedLoggerLib.c @@ -141,3 +141,20 @@ AdvancedLoggerGetLoggerInfo ( return mLoggerInfo; } + +/** + Helper function to return the log phase for each message. + + This function is intended to be used to distinguish between + various types of modules. + + @return Phase of current advanced logger instance. +**/ +UINT16 +EFIAPI +AdvancedLoggerGetPhase ( + VOID + ) +{ + return ADVANCED_LOGGER_PHASE_MM_CORE; +} diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/Pei64/AdvancedLoggerLib.c b/AdvLoggerPkg/Library/AdvancedLoggerLib/Pei64/AdvancedLoggerLib.c index 34ed79c008..1ce1c86502 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/Pei64/AdvancedLoggerLib.c +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/Pei64/AdvancedLoggerLib.c @@ -51,3 +51,20 @@ AdvancedLoggerGetLoggerInfo ( return LoggerInfoSec; } + +/** + Helper function to return the log phase for each message. + + This function is intended to be used to distinguish between + various types of modules. + + @return Phase of current advanced logger instance. +**/ +UINT16 +EFIAPI +AdvancedLoggerGetPhase ( + VOID + ) +{ + return ADVANCED_LOGGER_PHASE_PEI64; +} diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/PeiCore/AdvancedLoggerLib.c b/AdvLoggerPkg/Library/AdvancedLoggerLib/PeiCore/AdvancedLoggerLib.c index 46290086a5..8435eec55d 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/PeiCore/AdvancedLoggerLib.c +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/PeiCore/AdvancedLoggerLib.c @@ -588,3 +588,20 @@ AdvancedLoggerGetLoggerInfo ( return LoggerInfo; } + +/** + Helper function to return the log phase for each message. + + This function is intended to be used to distinguish between + various types of modules. + + @return Phase of current advanced logger instance. +**/ +UINT16 +EFIAPI +AdvancedLoggerGetPhase ( + VOID + ) +{ + return ADVANCED_LOGGER_PHASE_PEI; +} diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/Runtime/AdvancedLoggerLib.c b/AdvLoggerPkg/Library/AdvancedLoggerLib/Runtime/AdvancedLoggerLib.c index cd0cc8e815..1ea60cf42b 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/Runtime/AdvancedLoggerLib.c +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/Runtime/AdvancedLoggerLib.c @@ -112,6 +112,23 @@ AdvancedLoggerGetLoggerInfo ( return mLoggerInfo; } +/** + Helper function to return the log phase for each message. + + This function is intended to be used to distinguish between + various types of modules. + + @return Phase of current advanced logger instance. +**/ +UINT16 +EFIAPI +AdvancedLoggerGetPhase ( + VOID + ) +{ + return ADVANCED_LOGGER_PHASE_RUNTIME; +} + /** Inform all instances of Advanced Logger that ExitBoot Services has occurred. diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/Sec/AdvancedLoggerLib.c b/AdvLoggerPkg/Library/AdvancedLoggerLib/Sec/AdvancedLoggerLib.c index 08a9b61c66..01b09470f1 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/Sec/AdvancedLoggerLib.c +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/Sec/AdvancedLoggerLib.c @@ -71,3 +71,20 @@ AdvancedLoggerGetLoggerInfo ( return LoggerInfoSec; } + +/** + Helper function to return the log phase for each message. + + This function is intended to be used to distinguish between + various types of modules. + + @return Phase of current advanced logger instance. +**/ +UINT16 +EFIAPI +AdvancedLoggerGetPhase ( + VOID + ) +{ + return ADVANCED_LOGGER_PHASE_SEC; +} diff --git a/AdvLoggerPkg/Library/AdvancedLoggerLib/SmmCore/AdvancedLoggerLib.c b/AdvLoggerPkg/Library/AdvancedLoggerLib/SmmCore/AdvancedLoggerLib.c index 0625c620d7..4dcc224053 100644 --- a/AdvLoggerPkg/Library/AdvancedLoggerLib/SmmCore/AdvancedLoggerLib.c +++ b/AdvLoggerPkg/Library/AdvancedLoggerLib/SmmCore/AdvancedLoggerLib.c @@ -179,6 +179,23 @@ AdvancedLoggerGetLoggerInfo ( return mLoggerInfo; } +/** + Helper function to return the log phase for each message. + + This function is intended to be used to distinguish between + various types of modules. + + @return Phase of current advanced logger instance. +**/ +UINT16 +EFIAPI +AdvancedLoggerGetPhase ( + VOID + ) +{ + return ADVANCED_LOGGER_PHASE_SMM_CORE; +} + /** The constructor function initializes Logger Information pointer to ensure that the pointer is initialized in DXE - either by the constructor, or the first DEBUG message. diff --git a/AdvLoggerPkg/UnitTests/LineParser/LineParserTestApp.c b/AdvLoggerPkg/UnitTests/LineParser/LineParserTestApp.c index b87b3b1cf7..ead9bcf7d2 100644 --- a/AdvLoggerPkg/UnitTests/LineParser/LineParserTestApp.c +++ b/AdvLoggerPkg/UnitTests/LineParser/LineParserTestApp.c @@ -79,6 +79,27 @@ CHAR8 Line17[] = "09:06:45.012 : ents a combination of video output devices, th CHAR8 Line18[] = "09:06:45.012 : by this service is the subset of modes supported by the graphics controll\n"; CHAR8 Line19[] = "09:06:45.012 : er and the all of the video output devices represented by the handle.\n"; +CHAR8 Line00V2[] = "09:06:45.012 : [DXE] First normal test line\n"; +CHAR8 Line01V2[] = "09:06:45.012 : [DXE] The QueryMode() function returns information for an available graphics mod\n"; +CHAR8 Line02V2[] = "09:06:45.012 : [DXE] e that the graphics device and the set of active video output devices supp\n"; +CHAR8 Line03V2[] = "09:06:45.012 : [DXE] orts.\n"; +CHAR8 Line04V2[] = "09:06:45.012 : [DXE] If ModeNumber is not between 0 and MaxMode - 1, then EFI_INVALID_PARAMETER\n"; +CHAR8 Line05V2[] = "09:06:45.012 : [DXE] is returned.\n"; +CHAR8 Line06V2[] = "09:06:45.012 : [DXE] MaxMode is available from the Mode structure of the EFI_GRAPHICS_OUTPUT_PR\n"; +CHAR8 Line07V2[] = "09:06:45.012 : [DXE] OTOCOL.\n"; +CHAR8 Line08V2[] = "09:06:45.012 : [DXE] The size of the Info structure should never be assumed and the value of Si\n"; +CHAR8 Line09V2[] = "09:06:45.012 : [DXE] zeOfInfo is the only valid way to know the size of Info.\n"; +CHAR8 Line10V2[] = "09:06:45.012 : [DXE] \n"; +CHAR8 Line11V2[] = "09:06:45.012 : [DXE] If the EFI_GRAPHICS_OUTPUT_PROTOCOL is installed on the handle that repres\n"; +CHAR8 Line12V2[] = "09:06:45.012 : [DXE] ents a single video output device, then the set of modes returned by this \n"; +CHAR8 Line13V2[] = "09:06:45.012 : [DXE] service is the subset of modes supported by both the graphics controller a\n"; +CHAR8 Line14V2[] = "09:06:45.012 : [DXE] nd the video output device.\n"; +CHAR8 Line15V2[] = "09:06:45.012 : [DXE] \n"; +CHAR8 Line16V2[] = "09:06:45.012 : [DXE] If the EFI_GRAPHICS_OUTPUT_PROTOCOL is installed on the handle that repres\n"; +CHAR8 Line17V2[] = "09:06:45.012 : [DXE] ents a combination of video output devices, then the set of modes returned\n"; +CHAR8 Line18V2[] = "09:06:45.012 : [DXE] by this service is the subset of modes supported by the graphics controll\n"; +CHAR8 Line19V2[] = "09:06:45.012 : [DXE] er and the all of the video output devices represented by the handle.\n"; + /* spell-checker: enable */ STATIC ADVANCED_LOGGER_INFO mLoggerInfo = { @@ -227,6 +248,57 @@ InternalTestLoggerWrite ( return UNIT_TEST_PASSED; } +UNIT_TEST_STATUS +EFIAPI +InternalTestLoggerWriteV2 ( + IN UINTN DebugLevel, + IN CONST CHAR8 *Buffer, + IN UINTN NumberOfBytes + ) +{ + EFI_PHYSICAL_ADDRESS CurrentBuffer; + ADVANCED_LOGGER_MESSAGE_ENTRY_V2 *Entry; + UINTN EntrySize; + ADVANCED_LOGGER_INFO *LoggerInfo; + + UT_ASSERT_FALSE ((NumberOfBytes == 0) || (Buffer == NULL)); + + UT_ASSERT_FALSE (NumberOfBytes > MAX_UINT16); + + LoggerInfo = &mLoggerInfo; + EntrySize = MESSAGE_ENTRY_SIZE_V2 (OFFSET_OF (ADVANCED_LOGGER_MESSAGE_ENTRY_V2, MessageText), NumberOfBytes); + CurrentBuffer = LoggerInfo->LogCurrent; + + UT_ASSERT_TRUE ( + (LoggerInfo->LogBufferSize - + ((UINTN)(CurrentBuffer - LoggerInfo->LogBuffer))) > NumberOfBytes + ); + + LoggerInfo->LogCurrent = PA_FROM_PTR ((CHAR8_FROM_PA (LoggerInfo->LogCurrent) + EntrySize)); + Entry = (ADVANCED_LOGGER_MESSAGE_ENTRY_V2 *)PTR_FROM_PA (CurrentBuffer); + if ((Entry != (ADVANCED_LOGGER_MESSAGE_ENTRY_V2 *)ALIGN_POINTER (Entry, 8)) || // Insure pointer is on boundary + (Entry < (ADVANCED_LOGGER_MESSAGE_ENTRY_V2 *)PTR_FROM_PA (LoggerInfo->LogBuffer)) || // and within the log region + (Entry > (ADVANCED_LOGGER_MESSAGE_ENTRY_V2 *)PTR_FROM_PA (LoggerInfo->LogBuffer + LoggerInfo->LogBufferSize))) + { + UT_ASSERT_TRUE (FALSE); + } + + Entry->MajorVersion = ADVANCED_LOGGER_MSG_MAJ_VER; + Entry->MinorVersion = ADVANCED_LOGGER_MSG_MIN_VER; + Entry->TimeStamp = InternalGetPerformanceCounter (); + Entry->Phase = ADVANCED_LOGGER_PHASE_DXE; + + // DebugLevel is defined as a UINTN, so it is 32 bits in PEI and 64 bits in DXE. + // However, the DEBUG_* values and the PcdFixedDebugPrintErrorLevel are only 32 bits. + Entry->DebugLevel = (UINT32)DebugLevel; + Entry->MessageLen = (UINT16)NumberOfBytes; + Entry->MessageOffset = OFFSET_OF (ADVANCED_LOGGER_MESSAGE_ENTRY_V2, MessageText); + CopyMem (Entry->MessageText, Buffer, NumberOfBytes); + Entry->Signature = MESSAGE_ENTRY_SIGNATURE_V2; + + return UNIT_TEST_PASSED; +} + typedef struct { CHAR8 *IdString; CHAR8 *ExpectedLine; @@ -259,6 +331,27 @@ STATIC BASIC_TEST_CONTEXT mTest18 = { "Basic tests", Line18, NULL, EFI_SUCCESS STATIC BASIC_TEST_CONTEXT mTest19 = { "Basic tests", Line19, NULL, EFI_SUCCESS }; STATIC BASIC_TEST_CONTEXT mTest20 = { "End Of File", NULL, NULL, EFI_END_OF_FILE }; +STATIC BASIC_TEST_CONTEXT mTest00V2 = { "Basic tests", Line00V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest01V2 = { "Basic tests", Line01V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest02V2 = { "Basic tests", Line02V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest03V2 = { "Basic tests", Line03V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest04V2 = { "Basic tests", Line04V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest05V2 = { "Basic tests", Line05V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest06V2 = { "Basic tests", Line06V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest07V2 = { "Basic tests", Line07V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest08V2 = { "Basic tests", Line08V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest09V2 = { "Basic tests", Line09V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest10V2 = { "Basic tests", Line10V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest11V2 = { "Basic tests", Line11V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest12V2 = { "Basic tests", Line12V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest13V2 = { "Basic tests", Line13V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest14V2 = { "Basic tests", Line14V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest15V2 = { "Basic tests", Line15V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest16V2 = { "Basic tests", Line16V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest17V2 = { "Basic tests", Line17V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest18V2 = { "Basic tests", Line18V2, NULL, EFI_SUCCESS }; +STATIC BASIC_TEST_CONTEXT mTest19V2 = { "Basic tests", Line19V2, NULL, EFI_SUCCESS }; + /// ================================================================================================ /// ================================================================================================ /// @@ -340,6 +433,100 @@ InitializeInMemoryLog ( return UNIT_TEST_PASSED; } +/* + Initialize the v2 test in memory log + +*/ +STATIC +UNIT_TEST_STATUS +EFIAPI +InitializeInMemoryLogV2 ( + IN UNIT_TEST_CONTEXT Context + ) +{ + UINTN i; + EFI_STATUS Status; + UNIT_TEST_STATUS UnitTestStatus; + + if (mLoggerInfo.LogBuffer != 0LL) { + FreePages ((VOID *)mLoggerInfo.LogBuffer, IN_MEMORY_PAGES); + mLoggerInfo.LogBuffer = 0LL; + } + + // Repopulate the content with v2 messages + mLoggerInfo.LogBuffer = (EFI_PHYSICAL_ADDRESS)AllocatePages (IN_MEMORY_PAGES); + mLoggerInfo.LogBufferSize = EFI_PAGE_SIZE * IN_MEMORY_PAGES; + mLoggerInfo.LogCurrent = mLoggerInfo.LogBuffer; + + ZeroMem (&mMessageEntry, sizeof (mMessageEntry)); + + for (i = 0; i < ARRAY_SIZE (InternalMemoryLog); i++) { + UnitTestStatus = InternalTestLoggerWriteV2 ( + (i % 5) == 0 ? DEBUG_INFO : DEBUG_ERROR, + InternalMemoryLog[i], + AsciiStrLen (InternalMemoryLog[i]) + ); + UT_ASSERT_TRUE (UnitTestStatus == UNIT_TEST_PASSED); + } + + mLoggerProtocol.LoggerInfo = &mLoggerInfo; + Status = AdvancedLoggerAccessLibUnitTestInitialize (&mLoggerProtocol.AdvLoggerProtocol, ADV_LOG_MAX_SIZE); + UT_ASSERT_NOT_EFI_ERROR (Status) + + return UNIT_TEST_PASSED; +} + +/* + Initialize the v1 and v2 mixed test in memory log + +*/ +STATIC +UNIT_TEST_STATUS +EFIAPI +InitializeInMemoryLogV2Hybrid ( + IN UNIT_TEST_CONTEXT Context + ) +{ + UINTN i; + EFI_STATUS Status; + UNIT_TEST_STATUS UnitTestStatus; + + if (mLoggerInfo.LogBuffer != 0LL) { + FreePages ((VOID *)mLoggerInfo.LogBuffer, IN_MEMORY_PAGES); + mLoggerInfo.LogBuffer = 0LL; + } + + mLoggerInfo.LogBuffer = (EFI_PHYSICAL_ADDRESS)AllocatePages (IN_MEMORY_PAGES); + mLoggerInfo.LogBufferSize = EFI_PAGE_SIZE * IN_MEMORY_PAGES; + mLoggerInfo.LogCurrent = mLoggerInfo.LogBuffer; + + ZeroMem (&mMessageEntry, sizeof (mMessageEntry)); + + for (i = 0; i < 8; i++) { + UnitTestStatus = InternalTestLoggerWrite ( + (i % 5) == 0 ? DEBUG_INFO : DEBUG_ERROR, + InternalMemoryLog[i], + AsciiStrLen (InternalMemoryLog[i]) + ); + UT_ASSERT_TRUE (UnitTestStatus == UNIT_TEST_PASSED); + } + + for ( ; i < ARRAY_SIZE (InternalMemoryLog); i++) { + UnitTestStatus = InternalTestLoggerWriteV2 ( + ((i) % 5) == 0 ? DEBUG_INFO : DEBUG_ERROR, + InternalMemoryLog[i], + AsciiStrLen (InternalMemoryLog[i]) + ); + UT_ASSERT_TRUE (UnitTestStatus == UNIT_TEST_PASSED); + } + + mLoggerProtocol.LoggerInfo = &mLoggerInfo; + Status = AdvancedLoggerAccessLibUnitTestInitialize (&mLoggerProtocol.AdvLoggerProtocol, ADV_LOG_MAX_SIZE); + UT_ASSERT_NOT_EFI_ERROR (Status) + + return UNIT_TEST_PASSED; +} + /* Basic Tests @@ -466,6 +653,7 @@ LineParserTestAppEntry ( goto EXIT; } + // Start with legacy message entry tests // -----------Suite------------Description-------Class---------Test Function-Pre---Clean-Context AddTestCase (LineParserTests, "Init", "SelfInit", InitializeInMemoryLog, NULL, NULL, NULL); AddTestCase (LineParserTests, "Basic check", "BasicCheck", BasicTests, NULL, CleanUpTestContext, &mTest00); @@ -490,6 +678,54 @@ LineParserTestAppEntry ( AddTestCase (LineParserTests, "Line check 19", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest19); AddTestCase (LineParserTests, "Check EOF", "SelfCheck", EOFTest, NULL, CleanUpTestContext, &mTest20); + // Followed by V2 message entry tests + AddTestCase (LineParserTests, "Init V2", "SelfInit", InitializeInMemoryLogV2, NULL, NULL, NULL); + AddTestCase (LineParserTests, "Basic check V2", "BasicCheck", BasicTests, NULL, CleanUpTestContext, &mTest00V2); + AddTestCase (LineParserTests, "Line check 1 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest01V2); + AddTestCase (LineParserTests, "Line check 2 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest02V2); + AddTestCase (LineParserTests, "Line check 3 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest03V2); + AddTestCase (LineParserTests, "Line check 4 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest04V2); + AddTestCase (LineParserTests, "Line check 5 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest05V2); + AddTestCase (LineParserTests, "Line check 6 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest06V2); + AddTestCase (LineParserTests, "Line check 7 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest07V2); + AddTestCase (LineParserTests, "Line check 8 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest08V2); + AddTestCase (LineParserTests, "Line check 9 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest09V2); + AddTestCase (LineParserTests, "Line check 10 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest10V2); + AddTestCase (LineParserTests, "Line check 11 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest11V2); + AddTestCase (LineParserTests, "Line check 12 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest12V2); + AddTestCase (LineParserTests, "Line check 13 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest13V2); + AddTestCase (LineParserTests, "Line check 14 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest14V2); + AddTestCase (LineParserTests, "Line check 15 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest15V2); + AddTestCase (LineParserTests, "Line check 16 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest16V2); + AddTestCase (LineParserTests, "Line check 17 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest17V2); + AddTestCase (LineParserTests, "Line check 18 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest18V2); + AddTestCase (LineParserTests, "Line check 19 V2", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest19V2); + AddTestCase (LineParserTests, "Check EOF V2", "SelfCheck", EOFTest, NULL, CleanUpTestContext, &mTest20); + + // End with hybrid message entry tests + AddTestCase (LineParserTests, "Init V2 Hybrid", "SelfInit", InitializeInMemoryLogV2Hybrid, NULL, NULL, NULL); + AddTestCase (LineParserTests, "Basic check V2 Hybrid", "BasicCheck", BasicTests, NULL, CleanUpTestContext, &mTest00); + AddTestCase (LineParserTests, "Line check 1 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest01); + AddTestCase (LineParserTests, "Line check 2 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest02); + AddTestCase (LineParserTests, "Line check 3 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest03); + AddTestCase (LineParserTests, "Line check 4 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest04); + AddTestCase (LineParserTests, "Line check 5 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest05); + AddTestCase (LineParserTests, "Line check 6 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest06); + AddTestCase (LineParserTests, "Line check 7 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest07); + AddTestCase (LineParserTests, "Line check 8 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest08); + AddTestCase (LineParserTests, "Line check 9 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest09); + AddTestCase (LineParserTests, "Line check 10 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest10); + AddTestCase (LineParserTests, "Line check 11 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest11V2); + AddTestCase (LineParserTests, "Line check 12 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest12V2); + AddTestCase (LineParserTests, "Line check 13 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest13V2); + AddTestCase (LineParserTests, "Line check 14 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest14V2); + AddTestCase (LineParserTests, "Line check 15 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest15V2); + AddTestCase (LineParserTests, "Line check 16 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest16V2); + AddTestCase (LineParserTests, "Line check 17 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest17V2); + AddTestCase (LineParserTests, "Line check 18 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest18V2); + AddTestCase (LineParserTests, "Line check 19 V2 Hybrid", "SelfCheck", BasicTests, NULL, CleanUpTestContext, &mTest19V2); + AddTestCase (LineParserTests, "Check EOF V2 Hybrid", "SelfCheck", EOFTest, NULL, CleanUpTestContext, &mTest20); + // // Execute the tests. // @@ -500,10 +736,5 @@ LineParserTestAppEntry ( FreeUnitTestFramework (Fw); } - if (mLoggerInfo.LogBuffer != 0LL) { - FreePages ((VOID *)mLoggerInfo.LogBuffer, IN_MEMORY_PAGES); - mLoggerInfo.LogBuffer = 0LL; - } - return Status; }