OcLogAggregatorLib: Buffer log lines during high TPL when using fast file logging

Changelog.md

@@ -5,8 +5,9 @@ OpenCore Changelog
 - Updated emulated NVRAM save script to automatically install as launch daemon (Yosemite+) or logout hook (older macOS)
 - Fixed maximum click duration and double click speed for non-standard poll frequencies
 - Added support for pointer dwell-clicking
-- Prevented Apple firmware from adding additional security checks on top of emulated NVRAM driver
-- Fixed recursive loop on first log protocol line on some systems
+- Prevented Apple firmware from adding security checks on top of emulated NVRAM driver
+- Fixed recursive loop crash at first non-early log line on some systems
+- Fixed early log preservation when using unsafe fast file logging
 
 #### v0.8.5
 - Updated builtin firmware versions for SMBIOS and the rest

Library/OcDebugLibProtocol/OcDebugLibProtocol.c

@@ -28,9 +28,6 @@
 
 #define OC_LOG_BUFFER_SIZE  (2 * EFI_PAGE_SIZE)
 
-STATIC EFI_EVENT  mLogProtocolArrivedNotifyEvent;
-STATIC VOID       *mLogProtocolArrivedNotifyRegistration;
-
 STATIC UINT8  *mLogBuffer = NULL;
 STATIC UINT8  *mLogWalker = NULL;
 STATIC UINTN  mLogCount   = 0;
@@ -69,7 +66,6 @@ LogProtocolArrivedNotify (
   )
 {
   UINTN            Index;
-  EFI_STATUS       Status;
   OC_LOG_PROTOCOL  *OcLog;
   CHAR8            *Walker;
   UINTN            ErrorLevel;
@@ -78,18 +74,20 @@ LogProtocolArrivedNotify (
   //
   // Event arrives. Close it.
   //
-  gBS->CloseEvent (mLogProtocolArrivedNotifyEvent);
+  gBS->CloseEvent (Event);
 
-  Status = gBS->LocateProtocol (
-                  &gOcLogProtocolGuid,
-                  NULL,
-                  (VOID **)&OcLog
-                  );
+  OcLog = InternalGetOcLog ();
 
-  if (EFI_ERROR (Status) || (OcLog->Revision != OC_LOG_REVISION)) {
+  if (OcLog == NULL) {
     return;
   }
 
+  //
+  // Print messages without onscreen, as this has been done already.
+  //
+  CurrLogOpt      = OcLog->Options;
+  OcLog->Options &= ~OC_LOG_CONSOLE;
+
   Walker = (CHAR8 *)mLogBuffer;
   for (Index = 0; Index < mLogCount; ++Index) {
     //
@@ -98,16 +96,7 @@ LogProtocolArrivedNotify (
     CopyMem (&ErrorLevel, Walker, sizeof (ErrorLevel));
     Walker += sizeof (ErrorLevel);
 
-    //
-    // Print debug message without onscreen, as it is done by OutputString.
-    //
-    CurrLogOpt      = OcLog->Options;
-    OcLog->Options &= ~OC_LOG_CONSOLE;
     DebugPrint (ErrorLevel, "%a", Walker);
-    //
-    // Restore original value.
-    //
-    OcLog->Options = CurrLogOpt;
 
     //
     // Skip message chars.
@@ -122,6 +111,11 @@ LogProtocolArrivedNotify (
     ++Walker;
   }
 
+  //
+  // Restore original value.
+  //
+  OcLog->Options = CurrLogOpt;
+
   FreePool (mLogBuffer);
   mLogBuffer = NULL;
 }
@@ -134,6 +128,8 @@ OcBufferEarlyLog (
   )
 {
   EFI_STATUS  Status;
+  EFI_EVENT   Event;
+  VOID        *Registration;
 
   if (mLogBuffer == NULL) {
     mLogBuffer = AllocatePool (OC_LOG_BUFFER_SIZE);
@@ -151,18 +147,18 @@ OcBufferEarlyLog (
                     TPL_NOTIFY,
                     LogProtocolArrivedNotify,
                     NULL,
-                    &mLogProtocolArrivedNotifyEvent
+                    &Event
                     );
 
     if (!EFI_ERROR (Status)) {
       Status = gBS->RegisterProtocolNotify (
                       &gOcLogProtocolGuid,
-                      mLogProtocolArrivedNotifyEvent,
-                      &mLogProtocolArrivedNotifyRegistration
+                      Event,
+                      &Registration
                       );
 
       if (EFI_ERROR (Status)) {
-        gBS->CloseEvent (mLogProtocolArrivedNotifyEvent);
+        gBS->CloseEvent (Event);
       }
     }
   }

Library/OcLogAggregatorLib/OcLog.c

@@ -253,7 +253,6 @@ InternalLogAddEntry (
   UINT32                      KeySize;
   UINT32                      DataSize;
   UINT32                      TotalSize;
-  UINTN                       OldAsciiBufferOffset;
   UINTN                       WriteSize;
   UINTN                       WrittenSize;
 
@@ -365,15 +364,12 @@ InternalLogAddEntry (
     //
     // Write to internal buffer.
     //
-
-    OldAsciiBufferOffset = Private->AsciiBufferOffset;
-
     Status = AsciiStrCatS (Private->AsciiBuffer, Private->AsciiBufferSize, Private->TimingTxt);
     if (!EFI_ERROR (Status)) {
-      Private->AsciiBufferOffset += AsciiStrLen (Private->TimingTxt);
-      Status                      = AsciiStrCatS (Private->AsciiBuffer, Private->AsciiBufferSize, Private->LineBuffer);
+      Private->AsciiBufferWrittenOffset += AsciiStrLen (Private->TimingTxt);
+      Status                             = AsciiStrCatS (Private->AsciiBuffer, Private->AsciiBufferSize, Private->LineBuffer);
       if (!EFI_ERROR (Status)) {
-        Private->AsciiBufferOffset += AsciiStrLen (Private->LineBuffer);
+        Private->AsciiBufferWrittenOffset += AsciiStrLen (Private->LineBuffer);
       }
     }
 
@@ -381,16 +377,22 @@ InternalLogAddEntry (
     // Write to a file.
     //
     if (((OcLog->Options & OC_LOG_FILE) != 0) && (OcLog->FileSystem != NULL)) {
+      //
+      // Log lines may arrive when CurrentTpl > TPL_CALLBACK, we must batch them
+      // and emit them when we can, in both log methods.
+      //
       if (EfiGetCurrentTpl () <= TPL_CALLBACK) {
         if (OcLog->UnsafeLogFile != NULL) {
           //
           // For non-broken FAT32 driver this is fine. For driver with broken write
           // support (e.g. Aptio IV) this can result in corrupt file or unusable fs.
           //
-          WriteSize   = Private->AsciiBufferOffset - OldAsciiBufferOffset;
+          ASSERT (Private->AsciiBufferWrittenOffset >= Private->AsciiBufferFlushedOffset);
+          WriteSize   = Private->AsciiBufferWrittenOffset - Private->AsciiBufferFlushedOffset;
           WrittenSize = WriteSize;
-          OcLog->UnsafeLogFile->Write (OcLog->UnsafeLogFile, &WrittenSize, &Private->AsciiBuffer[OldAsciiBufferOffset]);
+          OcLog->UnsafeLogFile->Write (OcLog->UnsafeLogFile, &WrittenSize, &Private->AsciiBuffer[Private->AsciiBufferFlushedOffset]);
           OcLog->UnsafeLogFile->Flush (OcLog->UnsafeLogFile);
+          Private->AsciiBufferFlushedOffset += WrittenSize;
           if (WriteSize != WrittenSize) {
             DEBUG ((
               DEBUG_VERBOSE,

Library/OcLogAggregatorLib/OcLogInternal.h

@@ -41,7 +41,8 @@ typedef struct {
   CHAR16                   UnicodeLineBuffer[OC_LOG_LINE_BUFFER_SIZE];
   CHAR8                    AsciiBuffer[OC_LOG_BUFFER_SIZE];
   UINTN                    AsciiBufferSize;
-  UINTN                    AsciiBufferOffset;
+  UINTN                    AsciiBufferWrittenOffset;
+  UINTN                    AsciiBufferFlushedOffset;
   CHAR8                    NvramBuffer[OC_LOG_NVRAM_BUFFER_SIZE];
   UINTN                    NvramBufferSize;
   UINT32                   LogCounter;