Jump to content

AptioMemoryFix

vit9696

By vit9696,
in UEFI

 Share
595 posts in this topic

Recommended Posts

  • Popular Post
vit9696
vit9696
Posted
  • Author
  • Popular Post
Posted (edited)

Here and there: boot.efi printing now and then.

 

UPDATED: 31.01.2018 with fixes to certain misunderstandings and relevant NVRAM variables to control boot.efi logging behaviour.

 

Scroll all the way down to "How is this configured" if you need boot.efi debug printing.

 

Apple developers improved boot.efi printing quite a lot as of High Sierra.

The good thing is that we could make a good use of it, the bad thing, it is not too obvious.

 

Just like everything else boot.efi follows edk2-like error level reporting.

In release boot.efi only DEBUG_ERROR (0x80000000) is available, the rest are stripped.

 

First of all, boot.efi has an unholy amount of different print functions for all the needs.

So it will be a good start to list them. The function names may not be ideal, but I left the examples with strings to let one get an idea.

 

1. VOID PerfRecordPrint(CONST CHAR8 *Format, ...)

 

There are tons of its calls, for example:

PerfRecordPrint("Start");

PerfRecordPrint("Start OSName");

PerfRecordPrint("End OSName");

PerfRecordPrint("Start LoadCoreStorageConfiguration");

 

Its designation is to measure how much it took for boot.efi to execute each certain step and provide Apple the performance details.

Prior to 10.13 it was only possible to use it to log to NVRAM (efiboot-perf-record-data, efiboot-perf-record-data-size).

Starting with 10.13 it may also print via logging 'drivers', which print via different implementations.

 

2. VOID AppleLoggingPrintAll(UINTN ErrorLevel, CONST CHAR8 *Format, ...)

 

Known for printing especially crtitical messages like:

AppleLoggingPrintAll(DEBUG_ERROR, "This version of Mac OS X is not supported on this platform!\n");

AppleLoggingPrintAll(DEBUG_ERROR, "This system was automatically rebooted after panic\n");

 

Prior to 10.13 it was an unconditional formatted print via gST->ConOut or gST->StdErr if unavailable.

Starting with 10.13 it prints via logging 'drivers', which print via different implementations.

AppleLoggingPrintAll is designed to print via all the 'drivers'.

 

3. VOID FatalError(CONST CHAR8 *Format, ...)

 

Known usages, for example:

FatalError("Can not initialize console\n");

FatalError("ERROR!!! Recovery Image verification fail with status [0x%llx]\n", Status);

FatalError("Couldn't allocate bootArgs\n");

 

This is the well known print the error, sleep for 10 secs, and reboot.

Prior to 10.13 it used an unconditional formatted print via gST->ConOut or gST->StdErr if unavailable.

Starting with 10.13 it also prints via logging 'drivers', all of them.

 

4. VOID AppleLoggingPrintAllStyled(UINTN Level, CONST CHAR8 *Format, ...)

 

AppleLoggingPrintAllStyled(DEBUG_ERROR, "ERROR!!! Load prelinked kernel with status 0x%lx\n", Status);

AppleLoggingPrintAllStyled(DEBUG_ERROR, "(no root UUID found for boot device)\n");

AppleLoggingPrintAllStyled(DEBUG_ERROR, "Boot failed, sleeping for 10 seconds before exiting...\n");

AppleLoggingPrintAllStyled(0x80000000ui64, "ERROR!!! Uncompress prelinked kernel\n");

 

This one has always been printing via all of the logging 'drivers', starting with 10.11 at least.

 

Main internal implementation

 

Prior to 10.13 most of the prints went through a direct call through gST->ConOut/gST->StdErr, and printing drivers were almost unused and left unnoticed. Starting with 10.13 printing drivers are for almost everything, and we need to take good care of them. Interestingly they could also do additional formatting to the output (like timestamps).

 

These functions are the main functions Apple uses to print stuff.

To fully understand them one needs to go deeper into the implementation.

 

The idea is to have a formatter function similar to vprintf.

void AppleLoggingFormatter(CONST CHAR8 *Format, APPLE_LOGGING_PUTCHAR PutChar, AppleLoggingState *State, va_list *Args)

The arguments are as follows:

- a format string;

- some internal state;

- a putchar-like function, which will use the state;

- a variable list of arguments.

 

Prior to 10.13 everything went through a simple putchar function, that did not even need a state.

All the above functions but PerfRecordPrint would invoke DirectLoggingPrintf or alike under some condition and print to gST->ConOut or gST->ConOut.

 

 

 

  


void DirectLoggingPrintf(const char *Format, ...)
{
  va_list Args; // [rsp+20h] [rbp-20h]
  va_list va; // [rsp+58h] [rbp+18h]
 
  va_start(va, Format);
  va_copy(Args, va);
  AppleLoggingFormatter(Format, DirectLoggingPutChar, 0i64, &Args);
}
 
void DirectLoggingPutChar(UINT16 Char, AppleLoggingState *State)
{
  UINT32 TabCount; // edi
  EFI_SIMPLE_TEXT_OUTPUT_PROTOCOL *Out; // rcx MAPDST
 
  *(_WORD *)&mTmpChar[2] = 0;
  if ( Char == '\n' )
  {
    strcpy(mTmpChar, "\r");
    Out = gST->ConOut;
    if ( Out || (Out = gST->StdErr) != 0i64 )
      Out->OutputString(Out, (CHAR16 *)mTmpChar);
  }
  else if ( Char == '\t' )
  {
    strcpy(mTmpChar, " ");
    TabCount = 8;
    do
    {
      Out = gST->ConOut;
      if ( Out || (Out = gST->StdErr) != 0i64 )
        Out->OutputString(Out, (CHAR16 *)mTmpChar);
      --TabCount;
    }
    while ( TabCount );
    return;
  }
  *(_WORD *)mTmpChar = Char;
  Out = gST->ConOut;
  if ( Out || (Out = gST->StdErr) != 0i64 )
    Out->OutputString(Out, (CHAR16 *)mTmpChar);
}
 
void FatalError(const char *Format, ...)
{
  va_list v1; // [rsp+20h] [rbp-20h]
  va_list va; // [rsp+58h] [rbp+18h]
 
  va_start(va, Format);
  byte_87320 = 1;
  va_copy(v1, va);
  DirectLoggingPrintf(Format, DirectLoggingPutChar, 0i64, &v1);
  SetWakeFailure(2u, 0i64, 0);
  StallAndExit(EFI_ABORTED);
}

 

 

The exceptional PerfRecordPrint required a special nvram variable (efiboot-perf-record) to be present.

When it was there, boot.efi would print to a memory buffer until the very end, and will later store its data in efiboot-perf-record-data/efiboot-perf-record-data-size variables.

As a bonus it is also passed via BootArgs structure, so a bootloader can easily obtain this data too.

 

 

 

  


EFI_STATUS AllocatePerfRecordData(EFI_PHYSICAL_ADDRESS PerformanceDataStart, UINTN PerformanceDataSize)
{
  EFI_STATUS Status; // rax
  EFI_CPU_ARCH_PROTOCOL *CpuArch; // rcx
  EFI_PHYSICAL_ADDRESS Addr; // rax
  unsigned int PageNum; // eax
  EFI_PHYSICAL_ADDRESS v8; // rax
  __int64 v9; // rcx
  UINTN TmpSize; // [rsp+30h] [rbp-30h]
  EFI_GUID AppleBootVarGuid; // [rsp+38h] [rbp-28h]
 
  *AppleBootVarGuid.Data4 = 0x829F5C9941FE80A8i64;
  *&AppleBootVarGuid.Data1 = 0x4BBBAB2A7C436110i64;
  TmpSize = 0i64;
  if ( !PerformanceDataStart )
  {
    Status = gRT->GetVariable(L"efiboot-perf-record", &AppleBootVarGuid, 0i64, &TmpSize, 0i64);
    if ( Status != EFI_BUFFER_TOO_SMALL )
      return Status;
    gRT->SetVariable(L"efiboot-perf-record", &AppleBootVarGuid, 7u, 0i64, 0i64);
  }
  CpuArch = gEfiCpuArchProtocol;
  if ( gEfiCpuArchProtocol )
    goto LABEL_19;
  if ( (gBS->LocateProtocol(&gEfiCpuArchProtocolGuid, 0i64, &gEfiCpuArchProtocol) & 0x8000000000000000ui64) != 0i64 )
  {
    gEfiCpuArchProtocol = 0i64;
    goto LABEL_10;
  }
  CpuArch = gEfiCpuArchProtocol;
  if ( gEfiCpuArchProtocol )
  {
LABEL_19:
    Status = CpuArch->GetTimerValue(CpuArch, 0, &gStartTimerValue, &gStartTimerPeriod);
    if ( (Status & 0x8000000000000000ui64) != 0i64 )
      return Status;
    gStartTimerPeriod = DivideWithRemainder(1000000000000ui64, gStartTimerPeriod, 0i64);
  }
LABEL_10:
  Addr = 0xFFFFFFFFi64;
  if ( PerformanceDataStart )
    Addr = PerformanceDataStart;
  if ( !PerformanceDataStart )
    PerformanceDataSize = 0x1000i64;
  gPerfRecordDataBuffer = Addr;
  gPerfRecordDataBufferSize = PerformanceDataSize;
  byte_88B90 = PerformanceDataStart != 0;
  PageNum = BitShiftRight(PerformanceDataSize, 12);
  // AllocateMaxAddress = 1, AllocateAddress = 2
  Status = AllocatePages(((PerformanceDataStart != 0) + 1), EfiACPIReclaimMemory, PageNum, &gPerfRecordDataBuffer);
  if ( (Status & 0x8000000000000000ui64) != 0i64 )
  {
    gPerfRecordDataBuffer = 0i64;
  }
  else
  {
    v8 = gPerfRecordDataBuffer;
    gPrintBufferPtr = gPerfRecordDataBuffer;
    // Struct with magic, period, size, etc.
    *gPerfRecordDataBuffer = 'ootlefib';
    *(v8 + 8) = 0i64;
    *(v8 + 16) = gStartTimerPeriod;
    Status = DivideWithRemainder(gStartTimerValue, gStartTimerPeriod, 0i64);
    v9 = gPrintBufferPtr;
    *(gPrintBufferPtr + 24) = Status;
    *(v9 + 12) += 64;
  }
  return Status;
}
 
void SavePerfRecordData()
{
  BootArgs2 *BootArgs; // rdi
  EFI_GUID AppleBootVarGuid; // [rsp+30h] [rbp-30h]
  UINT32 Tmp; // [rsp+44h] [rbp-1Ch]
 
  BootArgs = gBootArgs;
  *AppleBootVarGuid.Data4 = 0x829F5C9941FE80A8i64;
  *&AppleBootVarGuid.Data1 = 0x4BBBAB2A7C436110i64;
  if ( gPerfRecordDataBuffer )
  {
    byte_88B90 = 1;
    Tmp = gPerfRecordDataBuffer;
    gRT->SetVariable(L"efiboot-perf-record-data", &AppleBootVarGuid, 6u, 4ui64, &Tmp);
    Tmp = gPerfRecordDataBufferSize;
    gRT->SetVariable(L"efiboot-perf-record-data-size", &AppleBootVarGuid, 6u, 4ui64, &Tmp);
    if ( BootArgs )
    {
      BootArgs->performanceDataStart = gPerfRecordDataBuffer;
      BootArgs->performanceDataSize = gPerfRecordDataBufferSize;
    }
  }
}
 
void PerfRecordPrint(const char *Format, ...)
{
  va_list Args; // [rsp+20h] [rbp-20h]
  va_list va; // [rsp+58h] [rbp+18h]
 
  va_start(va, Format);
  if ( gPerfRecordDataBuffer )
  {
    va_copy(Args, va);
    DoPerfRecordPrint(1, Format, &Args);
  }
}

 

 

Printing drivers used throughout 10.13

 

While printing drivers are not new to 10.13, and they existed in the previous operating systems, nothing really used them. Currently there are three, each exposing 2 funcs to enable/disable and its own bit used in logging usage mask.

 

1 — AppleLoggingConOutOrErrSet/AppleLoggingConOutOrErrPrint (classical ConOut or StdErr on failure)

2 - AppleLoggingStdErrSet/AppleLoggingStdErrPrint (StdErr or serial?)

4 - AppleLoggingFileSet/AppleLoggingFilePrint (BOOTER.LOG/BOOTER.OLD file on EFI partition)

 

So, from now on to be able to print via either of the driver one must do 3 things:

- include the bit in the printer driver mask (this is done pretty much everywhere);

- enable the driver itself by calling its Set function with 0 argument;

- pray that the driver works fine :D

 

Relevant decompiled code is included below:

 

 

 

  


void AppleLoggingStdErrSet(BOOLEAN Set)
{
  if ( Set == 1 )
  {
    mStdErrLoggingOn = 0;
  }
  else if ( !Set )
  {
    mStdErrLoggingOn = 1;
  }
}
 
void AppleLoggingStdErrPrint(UINTN Level, const char *Str, UINTN Size)
{
  CHAR16 Unicode[160]; // [rsp+20h] [rbp-140h]
 
  if ( mStdErrLoggingOn )
  {
    if ( gST->StdErr )
    {
      ConvertAsciiToUnicode(Str, Unicode);
      gST->StdErr->OutputString(gST->StdErr, Unicode);
    }
    else
    {
      PrintViaPort(Str, Size);
    }
  }
}
 
void AppleLoggingConOutOrErrSet(BOOLEAN Set)
{
  if ( Set == 1 )
  {
    mConOutOrErrLoggingOn = 0;
  }
  else if ( !Set )
  {
    mConOutOrErrLoggingOn = 1;
  }
}
 
void AppleLoggingConOutOrErrPrint(UINTN Level, const char *Str, UINTN Size)
{
  EFI_SIMPLE_TEXT_OUTPUT_PROTOCOL *Out; // rcx
  CHAR16 Buffer[152]; // [rsp+20h] [rbp-130h]
 
  if ( mConOutOrErrLoggingOn )
  {
    if ( gST )
    {
      ConvertAsciiToUnicode(Str, Buffer);
      Out = gST->ConOut;
      if ( Out || (Out = gST->StdErr) != 0i64 )
        Out->OutputString(Out, Buffer);
    }
  }
}
 
void AppleLoggingFileSet(BOOLEAN Set)
{
  if ( Set == 1 )
  {
    if ( gBooterLogRequested )
      CloseBooterLog();
    gBooterLogRequested = 0;
  }
  else if ( !Set )
  {
    if ( !gBooterLogRequested )
      RequestBooterLog();
    gBooterLogRequested = 1;
  }
}
 
void AppleLoggingFilePrint(UINTN Level, const char *Str, UINT32 Size)
{
  if ( gBooterLogRequested )
    PrintStringToBooterLog(Str, Size);
}
 
void PrintViaPort(const char *Str, UINTN Size)
{
  UINTN Index; // r10
  UINT8 Status; // al
 
  if ( Size )
  {
    Index = 0i64;
    do
    {
      do
        Status = __inbyte(0x3FDu);
      while ( !(Status & 0x20) );
      __outbyte(0x3F8u, Str[Index++]);
    }
    while ( Index != Size );
  }
}
 
void CloseBooterLog()
{
  if ( gEfiSimpleFileSystemNotifyEvent )
    gBS->CloseEvent(gEfiSimpleFileSystemNotifyEvent);
  if ( gBooterLog )
    gBooterLog->Close(gBooterLog);
}
 
void RequestBooterLog()
{
  void *v0; // rcx
  void *Event; // [rsp+28h] [rbp-8h]
 
  if ( !gEfiSimpleFileSystemNotifyEvent )
  {
    gBooterLogHandling = 0;
    if ( (gBS->CreateEvent(0x200u, 8ui64, EfiSimpleFileSystemNotifyHandler, 0i64, &Event) & 0x8000000000000000ui64) == 0i64
      && (gBS->RegisterProtocolNotify(&gEfiSimpleFileSystemProtocolGuid, Event, &qword_8A780) & 0x8000000000000000ui64) == 0i64 )
    {
      v0 = Event;
      gEfiSimpleFileSystemNotifyEvent = Event;
      Event = 0i64;
      gBS->SignalEvent(v0);
    }
    if ( Event )
      gBS->CloseEvent(Event);
  }
}
 
void EfiSimpleFileSystemNotifyHandler(EFI_EVENT Context)
{
  void *Found; // r15
  UINTN Index; // rdi
  EFI_DEVICE_PATH_PROTOCOL *DevicePath; // rax
  __int64 Tmp; // [rsp+28h] [rbp-48h]
  EFI_SIMPLE_FILE_SYSTEM_PROTOCOL *Volume; // [rsp+30h] [rbp-40h]
  UINTN Num; // [rsp+38h] [rbp-38h]
  _QWORD *Arr; // [rsp+40h] [rbp-30h]
 
  if ( gBooterLogHandling != 1 && !gBooterLog )
  {
    gBooterLogHandling = 1;
    Num = 0i64;
    if ( (gBS->LocateHandleBuffer(ByRegisterNotify, &gEfiSimpleFileSystemProtocolGuid, gFileSystemHandlers, &Num, &Arr) & 0x8000000000000000ui64) == 0i64 )
    {
      if ( Num )
      {
        Found = 0i64;
        Index = 0i64;
        while ( 1 )
        {
          if ( (gBS->HandleProtocol(Arr[Index], &gEfiPartTypeSystemPartGuid, &Tmp) & 0x8000000000000000ui64) == 0i64 )
          {
            DevicePath = LocateDevicePathProtocol(Arr[Index]);
            if ( sub_162B6(DevicePath) )        // Checks if suitable
              break;
          }
          if ( ++Index >= Num )
            goto LABEL_12;
        }
        Found = Arr[Index];
      }
      else
      {
        Found = 0i64;
      }
LABEL_12:
      gBS->FreePool(Arr);
      if ( Found
        && (gBS->HandleProtocol(Found, &gEfiSimpleFileSystemProtocolGuid, &Volume) & 0x8000000000000000ui64) == 0i64
        && (Volume->OpenVolume(Volume, &gEfiPartitionFileProtocol) & 0x8000000000000000ui64) == 0i64 )
      {
        OpenBooterLog();
      }
    }
    if ( Num )
      gBS->SignalEvent(Context);
    gBooterLogHandling = 0;
  }
}
 
EFI_STATUS OpenBooterLog()
{
  EFI_STATUS Status; // rax
  UINTN Pos; // [rsp+30h] [rbp-10h]
  EFI_FILE_PROTOCOL *BooterLog; // [rsp+38h] [rbp-8h]
 
  if ( !gEfiPartitionFileProtocol )
    return EFI_NOT_READY;
  // EFI_FILE_MODE_CREATE|EFI_FILE_MODE_READ|EFI_FILE_MODE_WRITE
  Status = gEfiPartitionFileProtocol->Open(
             gEfiPartitionFileProtocol,
             &BooterLog,
             L"BOOTER.LOG",
             0x8000000000000003ui64,
             0i64);
  if ( (Status & 0x8000000000000000ui64) == 0i64 )
  {
    Status = BooterLog->SetPosition(BooterLog, 0xFFFFFFFFFFFFFFFFui64);
    if ( (Status & 0x8000000000000000ui64) == 0i64 )
    {
      Status = BooterLog->GetPosition(BooterLog, &Pos);
      if ( (Status & 0x8000000000000000ui64) == 0i64 )
      {
        gBooterLog = BooterLog;
        gBooterLogPosition = Pos;
      }
    }
  }
  return Status;
}
 
void PrintStringToBooterLog(const char *Str, UINTN Size)
{
  EFI_FILE_PROTOCOL *BooterLog; // rcx
 
  BooterLog = gBooterLog;
  if ( !gBooterLog )
    return;
  if ( gBooterLogPosition + Size < 0x80001 )
    goto SKIP_CREATING_OLD;
  if ( (RotateBooterLog() & 0x8000000000000000ui64) == 0i64 )
  {
    BooterLog = gBooterLog;
SKIP_CREATING_OLD:
    if ( (BooterLog->Write(BooterLog, &Size, Str) & 0x8000000000000000ui64) == 0i64
      && (gBooterLog->Flush(gBooterLog) & 0x8000000000000000ui64) == 0i64 )
    {
      gBooterLogPosition += Size;
      return;
    }
  }
  if ( gBooterLog )
    gBooterLog->Close(gBooterLog);
  gBooterLog = 0i64;
  gBooterLogPosition = 0i64;
}
 
EFI_STATUS RotateBooterLog()
{
  EFI_STATUS Status; // rdi
  UINT8 *FileInfo; // rsi
  EFI_FILE_PROTOCOL *OldBooter; // [rsp+30h] [rbp-20h]
  __int64 FileInfoSz; // [rsp+38h] [rbp-18h]
 
  Status = EFI_OUT_OF_RESOURCES;
  FileInfoSz = 102i64;
  FileInfo = AllocateBytesFromPool(102i64);
  if ( FileInfo )
  {
    if ( (gEfiPartitionFileProtocol->Open(gEfiPartitionFileProtocol, &OldBooter, L"BOOTER.OLD", 3ui64, 0i64) & 0x8000000000000000ui64) != 0i64
      || OldBooter->Delete(OldBooter) != 2 )
    {
      Status = gBooterLog->GetInfo(gBooterLog, &gEfiFileInfoGuid, &FileInfoSz, FileInfo);
      if ( (Status & 0x8000000000000000ui64) == 0i64 )
      {
        gBS->CopyMem(FileInfo + 80, L"BOOTER.OLD", 0x16ui64);
        *FileInfo = 102i64;
        Status = gBooterLog->SetInfo(gBooterLog, &gEfiFileInfoGuid, 102ui64, FileInfo);
        if ( (Status & 0x8000000000000000ui64) == 0i64 )
        {
          Status = gBooterLog->Close(gBooterLog);
          if ( (Status & 0x8000000000000000ui64) == 0i64 )
            Status = OpenBooterLog();
        }
      }
    }
    else
    {
      Status = EFI_ACCESS_DENIED;
    }
    gBS->FreePool(FileInfo);
  }
  return Status;
}

 

 

So, the functions are now modified to print their output via 2 new interfaces:

void AppleLoggingPrintfStyled(UINTN PrinterMask, UINTN Level, const char *Format, va_list *Args);

void AppleLoggingPrintf(UINTN PrinterMask, UINTN Level, const char *Format, va_list *Args);

 

PrinterMask is responsible for choosing the drivers to use. Currently Apple seems to pass 0x37 everywhere.

So it means that by default all the drivers should at least try printing.

The only difference between Styled and non-styled is that styled depending on gBootArgDebug.variable value may print a timestamp.

 

 

 

  


void AppleLoggingPrintfStyled(UINTN PrinterMask, UINTN Level, const char *Format, va_list *Args)
{
  UINTN Size; // rax
  UINTN v9; // r14
  char *v10; // rsi
  signed __int64 Index; // rdi
  __int64 Day; // [rsp+20h] [rbp-130h]
  __int64 Year; // [rsp+28h] [rbp-128h]
  __int64 Hour; // [rsp+30h] [rbp-120h]
  __int64 Minute; // [rsp+38h] [rbp-118h]
  __int64 Second; // [rsp+40h] [rbp-110h]
  char Buffer[150]; // [rsp+50h] [rbp-100h]
  AppleLoggingState State; // [rsp+E8h] [rbp-68h]
  EFI_TIME Time; // [rsp+110h] [rbp-40h]
 
  State.PrinterMask = PrinterMask;
  State.PrinterLevel = Level;
  State.PrinterBuffer = Buffer;
  State.PrinterBufferPtr = Buffer;
  State.PrinterBufferEnd = &Buffer[149];
  if ( gBootArgDebug.variable & 4 && (gRT->GetTime(&Time, 0i64) & 0x8000000000000000ui64) == 0i64 )
  {
    LODWORD(Second) = Time.Second;
    LODWORD(Minute) = Time.Minute;
    LODWORD(Hour) = Time.Hour;
    LODWORD(Year) = Time.Year;
    LODWORD(Day) = Time.Day;
    Size = AppleLoggingDebugPrinter(
             Buffer,
             149ui64,
             "%02d/%02d/%02d %02d:%02d:%02d ",
             Time.Month,
             Day,
             Year,
             Hour,
             Minute,
             Second);
    State.PrinterBufferPtr = State.PrinterBufferPtr + Size;
  }
  AppleLoggingFormatter(Format, AppleLoggingPutChar, &State, Args);
  // And this is for flushing once again
  if ( State.PrinterBufferPtr > State.PrinterBuffer )
  {
    *State.PrinterBufferPtr = 0;
    v9 = State.PrinterBuffer;
    v10 = State.PrinterBufferPtr - State.PrinterBuffer;
    Index = 2i64;
    do
    {
      if ( PrinterMask & mAppleLoggingFuncs[Index - 2] )
        (mAppleLoggingFuncs[Index])(Level, v9, v10);
      Index += 3i64;
    }
    while ( Index != 11 );
  }
}
 
void AppleLoggingPrintf(UINTN PrinterMask, UINTN Level, const char *Format, va_list *Args)
{
  UINTN Buf; // r15
  UINTN Size; // r12
  UINTN Index; // rbx
  char Buffer[150]; // [rsp+20h] [rbp-F0h]
  AppleLoggingState State; // [rsp+B8h] [rbp-58h]
 
  State.PrinterMask = PrinterMask;
  State.PrinterLevel = Level;
  State.PrinterBuffer = Buffer;
  State.PrinterBufferPtr = Buffer;
  State.PrinterBufferEnd = &Buffer[149];
  AppleLoggingFormatter(Format, AppleLoggingPutChar, &State, Args);
  // AppleLoggingPutChar flushes the buffer when it reaches the limit (150 chars).
  // Yet it won't flush the last one, so it is done here.
  if ( State.PrinterBufferPtr > State.PrinterBuffer )
  {
    *State.PrinterBufferPtr = 0;
    Buf = State.PrinterBuffer;
    Size = State.PrinterBufferPtr - State.PrinterBuffer;
    Index = 2i64;
    do
    {
      // if (PrinterMask & mAppleLoggingFuncs[Index].Mask)
      //   mAppleLoggingFuncs[Index].Log(Level, Buf, Size);
      // Index++;
      if ( PrinterMask & mAppleLoggingFuncs[Index - 2] )
        (mAppleLoggingFuncs[Index])(Level, Buf, Size);
      Index += 3i64;
    }
    while ( Index != 11 );
  }
}
 
void AppleLoggingPutChar(int Symbol, AppleLoggingState *State)
{
  INTN TabNum; // rsi
  _BYTE *Buf; // rax
  UINTN Mask; // rsi
  UINTN Lebel; // r15
  UINTN Buffer; // r13
  char *Len; // rbx
  signed __int64 Index; // rdi
  char Char; // [rsp+24h] [rbp-3Ch] MAPDST
 
  Char = Symbol;
  if ( Symbol == '\n' )
  {
    AppleLoggingPutChar('\r', State);
  }
  else if ( Symbol == '\t' )
  {
    TabNum = -4i64;                             // note: changed from 8 in 10.12 and earlier
    do
    {
      AppleLoggingPutChar(' ', State);
      ++TabNum;
    }
    while ( TabNum );
  }
  Buf = State->PrinterBufferPtr;
  if ( Buf == (State->PrinterBufferEnd - 1) )
  {
    Buf[1] = 0;
    Mask = State->PrinterMask;
    Lebel = State->PrinterLevel;
    Buffer = State->PrinterBuffer;
    Len = State->PrinterBufferPtr - Buffer;
    Index = 2i64;
    do
    {
      if ( Mask & mAppleLoggingFuncs[Index - 2] )
        (mAppleLoggingFuncs[Index])(Lebel, Buffer, Len);
      Index += 3i64;
    }
    while ( Index != 11 );
    Buf = State->PrinterBuffer;
    State->PrinterBufferPtr = Buf;
  }
  *Buf = Char;
  ++State->PrinterBufferPtr;
}

 

 

What are the changes to the top functions?

There is nothing interesting besides the use of AppleLoggingPrintfs. But FatalError and PerfRecordPrint got something special.

First one no longer uses direct ConOut/StdErr logging for printing errors, but has a well-known "does printf work??" message going through it.

So we can conclude that AppleLoggingPrintf does not work on most of hacks.

Second one will now use AppleLoggingPrintfStyled to print debug messages, which means if AppleLoggingPrintfStyled begins to work, we will be able to print the whole boot.efi trace log onscreen.

 

 

 

  


void FatalError(const char *Format, ...)
{
  va_list Args; // [rsp+20h] [rbp-30h]
  va_list va; // [rsp+68h] [rbp+18h]
 
  va_start(va, Format);
  DirectLoggingPrintf("does printf work??\n");
  byte_8A650 = 1;
  va_copy(Args, va);
  AppleLoggingPrintf(0x37ui64, DEBUG_ERROR, Format, &Args);
  SetWakeFailure(2u, 0i64, 0);
  StallAndExit(EFI_ABORTED);
}
 
void PerfRecordPrint(const char *Format, ...)
{
  va_list args; // [rsp+20h] [rbp-20h]
  va_list va; // [rsp+58h] [rbp+18h]
 
  va_start(va, Format);
  va_copy(args, va);
  if ( gPerfRecordDataBuffer )
  {
    PerfRecordPrintBuf(1ui64, Format, &args);
  }
  else
  {
    AppleLoggingPrintfStyled(0x37ui64, 0x80000000ui64, Format, &args);
    AppleLoggingPrintAll(0x80000000ui64, "\n");
  }
}

 

 

How is this configured?

 

Initially I confused this part quite a lot due to various circumstances :D. Now it is much better.

To configure the driver logging boot.efi uses nvram bootercfg and bootercfg-once variables, which are very similar to boot-args.

bootercfg-once is a way to change the debugging for a single boot only, and it is read and deleted by boot.efi only if bootercfg is not present.

 

The accepted values for all the arguments are hexadecimal 64-bit values with or without 0x prefix:

— log=VALUE

— debug=VALUE

— level=VALUE

— kc-read-size=VALUE

 

For log the valid bits are enabled log drivers:

1 — AppleLoggingConOutOrErrSet/AppleLoggingConOutOrErrPrint (classical ConOut or StdErr on failure)

2 — AppleLoggingStdErrSet/AppleLoggingStdErrPrint (StdErr or serial?)

4 — AppleLoggingFileSet/AppleLoggingFilePrint (BOOTER.LOG/BOOTER.OLD file on EFI partition)

 

For debug the valid bits are:

1 — enables print something to BOOTER.LOG (stripped code implies there may be a crash)

2 — enables perf logging to /efi/debug-log in the device three

4 — enables timestamp printing for styled printf calls

 

Thus to quickly disable the logging functionality in -v mode in boot.efi you could use sudo nvram bootercfg="log=0".

 

For level the value is the verbosity level of DEBUG output. Since everything but 0x80000000 is stripped from the binary, and this is the default value, it is not very handy.

 

For kc-reead-size the value is a chunk size used for buffered i/o from the network (unsupported obviously) or the disk for stuff like prelinkedkernel reading. By default it is set to 1MB (0x100000), but you may try to increase it for a millisecond faster booting :D

 

Interanlly there are three functions to configure printing driver usage, in particular these:

- AppleLoggingSet (a dedicated func to speficific drivers on or off)

- AppleLoggingEnable

- AppleLoggingDisable

 

The only usage of the first one is in boot key parsing code.

Pressing Cmd + V (verbose mode) will enable the 1st driver (classical ConOut or StdErr on failure).

It is really weird, because -v in boot-args does not do it, but I guess Cmd + V is considered more special than -v.

 

Which adds to the top of the ice-berg is that AppleLoggingDisable is called before boot.efi goes down or booter services will be no longer available due to os start:

- right before rebooting into Recovery

- right before chainloading a second boot.efi

- before printing "Boot failed, sleeping for 10 seconds"

- during memory map allocation close to XNU start

- right before EXIT_BOOT_SERVICES

 

 

 

  


void AppleLoggingSet(UINTN Mask, UINT32 Status)
{
  UINTN Index; // rbx
 
  Index = 1i64;
  do
  {
    if ( Mask & mAppleLoggingFuncs[Index - 1] )
      (mAppleLoggingFuncs[Index])(Status);      // Calls Set funcs, 0 means ENABLE driver
    Index += 3i64;
  }
  while ( Index != 10 );
}

// Only called in the beginning of boot.efi, it enables all the requested drivers in nvram.
void AppleLoggingEnable()
{
  __int64 Requested; // rsi
  UINTN Index; // rdi
  EFI_TIME v2; // [rsp+28h] [rbp-28h]

  *&v2.Nanosecond = 0i64;
  *&v2.Year = 0i64;
  gBS->SetMem(&v2, 0x10ui64, 0);
  if ( gRT )
    gRT->GetTime(&v2, 0i64);
  Requested = gBootArgLog.variable;
  Index = 1i64;
  do
  {
    if ( Requested & mAppleLoggingFuncs[Index - 1] )
      (mAppleLoggingFuncs[Index])(0i64);
    Index += 3i64;
  }
  while ( Index != 10 );
}

void AppleLoggingDisable()
{
  const char *StrStart; // rcx
  __int64 StrEnd; // rdx
  unsigned __int64 Drivers; // rsi
  signed __int64 Index; // rdi
  EFI_TIME Time; // [rsp+28h] [rbp-28h]

  // There was a debug print here ><
  *&Time.Nanosecond = 0i64;
  *&Time.Year = 0i64;
  gBS->SetMem(&Time, 0x10ui64, 0);
  if ( gRT )
    gRT->GetTime(&Time, 0i64);
  if ( gBootArgDebug.variable & 1 )
  {
    StrStart = gUninitialisedPtr1;
    StrEnd = gUninitialisedPtr2;
    if ( gUninitialisedPtr1 < gUninitialisedPtr2 )
    {
      if ( !gBooterLogRequested )
      {
        RequestBooterLog();
        StrStart = gUninitialisedPtr1;
        StrEnd = gUninitialisedPtr2;
      }
      gBooterLogRequested = 1;
      PrintStringToBooterLog(StrStart, StrEnd - StrStart);
      if ( gBooterLogRequested )
        CloseBooterLog();
      gBooterLogRequested = 0;
    }
  }
  Drivers = gBootArgLog.variable & ~2ui64;      // Ignores StdErr driver
  Index = 1i64;
  do
  {
    if ( Drivers & mAppleLoggingFuncs[Index - 1] )
      (mAppleLoggingFuncs[Index])(1i64);
    Index += 3i64;
  }
  while ( Index != 10 );
  LOBYTE(gBootArgDebug.variable) &= ~4u;        // disables date prints
}

/*

gBootArgLog     ConfigurableParameter <1, offset "log", 0>
gBootArgDebug   ConfigurableParameter <1, offset "debug", 0>
gBootArgLevel   ConfigurableParameter <1, offset "level", 80000000h>
gKcReadSize     ConfigurableParameter <1, offset "kc-read-size", 100000h>

gConfigurableArgs 
  dq offset gBootArgLog
  dq offset gBootArgDebug
  dq offset gKcReadSize
  dq offset gBootArgLevel

*/

void ReadBooterCfg()
{
  UINTN Index; // rsi
  char Buffer[512]; // [rsp+30h] [rbp-240h]
  char *Str; // [rsp+230h] [rbp-40h]
  UINTN Present; // [rsp+238h] [rbp-38h]
  UINTN Size; // [rsp+240h] [rbp-30h]

  Size = 512i64;
  if ( (gRT->GetVariable(L"bootercfg-once", &gAppleBootVariableGuid, 0i64, &Size, Buffer) & 0x8000000000000000ui64) != 0i64 )
  {
    Size = 512i64;
    if ( (gRT->GetVariable(L"bootercfg", &gAppleBootVariableGuid, 0i64, &Size, Buffer) & 0x8000000000000000ui64) != 0i64 )
      return;
  }
  else
  {
    gRT->SetVariable(L"bootercfg-once", &gAppleBootVariableGuid, 0, 0i64, 0i64);
  }
  Buffer[Size] = 0;
  Index = 0i64;
  do
  {
    if ( ArgumentExists(Buffer, gConfigurableArgs[Index]->arg, &Str, &Present) >= 0 )
    {
      if ( Present )
        gConfigurableArgs[Index]->variable = strtoull(Str, 0i64, 16u);
      else
        gConfigurableArgs[Index]->variable = 0i64;
    }
    ++Index;
  }
  while ( Index != 4 );
}

 

 

To unconditionally and quickly enable the debug log in 10.13 one may still patch the check in the beginning of the logger function (ConOut/StdErr method).

But I suppose it will be better to implement some interface to set bootercfg from Clover (or at least stop it from messing with it): 

48 81 EC 50 01 00 00 80 3D -> 48 81 EC 50 01 00 00 EB 07
Edited by vit9696
  • Like 21
Link to comment
Share on other sites
Pavo
Pavo
Posted
Posted

@Zenith432, yes, it makes good sense to me. Committed.

 

@fabiosun, thx for the report.

 

@Download-Fritz, in my opinion, it is likely not worth it. Without the option it will hardly be able to boot anyway.

with the latest commit, something is broke

Building ... /Users/henrybrock/Desktop/AptioFix/edk2/AptioFixPkg/Platform/AptioMemoryFix/AptioMemoryFix.inf [X64]
"ld" -arch x86_64 -u __ModuleEntryPoint -e __ModuleEntryPoint -preload -segalign 0x20 -pie -all_load -dead_strip -seg1addr 0x240 -map /Users/henrybrock/Desktop/AptioFix/edk2/Build/AptioFixPkg/RELEASE_XCODE5/X64/AptioFixPkg/Platform/AptioMemoryFix/AptioMemoryFix/DEBUG/AptioMemoryFix.map -o /Users/henrybrock/Desktop/AptioFix/edk2/Build/AptioFixPkg/RELEASE_XCODE5/X64/AptioFixPkg/Platform/AptioMemoryFix/AptioMemoryFix/DEBUG/AptioMemoryFix.dll  -filelist /Users/henrybrock/Desktop/AptioFix/edk2/Build/AptioFixPkg/RELEASE_XCODE5/X64/AptioFixPkg/Platform/AptioMemoryFix/AptioMemoryFix/OUTPUT/static_library_files.lst
Undefined symbols for architecture x86_64:
  "_gRtShimsDataEnd", referenced from:
      _MOStartImage in lto.o
  "_RtShimGetNextVariableName", referenced from:
      _MOStartImage in lto.o
  "_RtShimSetVariable", referenced from:
      _MOStartImage in lto.o
  "_RtShimSetTime", referenced from:
      _MOStartImage in lto.o
  "_RtShimGetNextHighMonoCount", referenced from:
      _MOStartImage in lto.o
  "_RtShimResetSystem", referenced from:
      _MOStartImage in lto.o
  "_RtShimGetTime", referenced from:
      _MOStartImage in lto.o
  "_RtShimGetWakeupTime", referenced from:
      _MOStartImage in lto.o
  "_RtShimSetWakeupTime", referenced from:
      _MOStartImage in lto.o
  "_RtShimGetVariable", referenced from:
      _MOStartImage in lto.o
  "_gRtShimsDataStart", referenced from:
      _OvrSetVirtualAddressMap in lto.o
      _MOStartImage in lto.o
ld: symbol(s) not found for architecture x86_64
make: *** [/Users/henrybrock/Desktop/AptioFix/edk2/Build/AptioFixPkg/RELEASE_XCODE5/X64/AptioFixPkg/Platform/AptioMemoryFix/AptioMemoryFix/DEBUG/AptioMemoryFix.dll] Error 1


build.py...
 : error 7000: Failed to execute command
	make tbuild [/Users/henrybrock/Desktop/AptioFix/edk2/Build/AptioFixPkg/RELEASE_XCODE5/X64/AptioFixPkg/Platform/AptioMemoryFix/AptioMemoryFix]


build.py...
 : error F002: Failed to build module
	/Users/henrybrock/Desktop/AptioFix/edk2/AptioFixPkg/Platform/AptioMemoryFix/AptioMemoryFix.inf [X64, XCODE5, RELEASE]

- Failed -
Build end time: 13:46:12, Jan.20 2018
Build total time: 00:00:02
Link to comment
Share on other sites
vit9696
vit9696
Posted
  • Author
Posted

Agh, did not realise that Clover still used old naming style. Fixed.

 

fabiosun, well, only half of that is from AptioFix (in particular, only the slide unavailable part), and to my eyes it is useful enough to be left enabled by default.

Since if one still has issues when booting and decides to use a custom slide, he will at least be able to see which ones definitely to avoid.

 

The rest is from boot.efi, and it is pretty much the initialisation issue I described on the previous page. You are best to patch boot.efi, if this annoys you (will require some reversing and asm knowledge).

A proper fix (I checked PE docs, and it looks like uninitialised section should be zero-filled) would likely be to ensure that uninitialised boot.efi section portions are zero-filled.

Link to comment
Share on other sites
Pavo
Pavo
Posted
Posted

Ok fixed the build issue from last commit, just had to remove the cached build config and rebuild. Updated my build script to check if EDK2 has any repo updates and also to remove cached build config if no updates are detected.

 

Ok now the script shows spinning progress while running, requested by users

 

AptioMemory_Builder.sh.zip

  • Like 3
Link to comment
Share on other sites
MakAsus
MakAsus
Posted
Posted

Created a repo on Github to be able to track changes

https://github.com/Pavo-IM/AptioMemFix

I tried your script and removed from it &>/dev/null to see errors.

It still does not compile with such errors:

 

 

build.py...

 : error 7000: Failed to execute command

make tbuild [/users/sergeyls/Desktop/AptioFix/edk2/Build/AptioFixPkg/DEBUG_XCODE5/X64/MdePkg/Library/BaseLib/BaseLib]

 

 

build.py...

 : error F002: Failed to build module

/Users/sergeyls/Desktop/AptioFix/edk2/MdePkg/Library/BaseLib/BaseLib.inf [X64, XCODE5, DEBUG]

 

Link to comment
Share on other sites
MakAsus
MakAsus
Posted
Posted

 

I tried your script and removed from it &>/dev/null to see errors.

It still does not compile with such errors:

 

 

build.py...

 : error 7000: Failed to execute command

make tbuild [/users/sergeyls/Desktop/AptioFix/edk2/Build/AptioFixPkg/DEBUG_XCODE5/X64/MdePkg/Library/BaseLib/BaseLib]

 

 

build.py...

 : error F002: Failed to build module

/Users/sergeyls/Desktop/AptioFix/edk2/MdePkg/Library/BaseLib/BaseLib.inf [X64, XCODE5, DEBUG]

 

Thanks The problem is solved. I just copied nasm into the folder /Library/Developer/CommandLineTools/usr/bin/

  • Like 1
Link to comment
Share on other sites
Pavo
Pavo
Posted
Posted

Just made a docker container that will auto build AptioMemoryFix using EDK2. Great thing about this is that it can run on any OS that has Docker installed. This is using CentOS 7 with GCC 4.8 with clang to build.

 

If you would like to use this make sure you have Docker installed and do the following commands.

Initial run:

docker pull pavo/aptiofix_builder

docker run -it -v $HOME/Desktop/AptioFix_Build:/root/AptioFix_Build --name AptioFixBuild pavo/aptiofix_builder

docker commit AptioFixBuild initial_build

docker rm AptioFixBuild

This will create a folder on the users Desktop and mount it into the docker container, once the build process is done it will copy the EFI modules into that folder.

 

 

To re-build ie.... if AptioMemory, EDK2 has had changes do the following commands:

docker run -it -v $HOME/Desktop/AptioFix_Build:/root/AptioFix_Build --name AptioFixBuild initial_build 

This will check to see if there is any updates to AptioMemoryFix repo (vit9696), EDK2 repo and update it if there is. It will also rebuild the EFI modules.

 

Default build is both DEBUG and RELEASE. If you want to build either a RELEASE or a DEBUG version do the following commands:

docker run -it -v $HOME/Desktop/AptioFix_Build:/root/AptioFix_Build --name AptioFixBuild --entrypoint /root/setup.sh initial_build RELEASE

or:

docker run -it -v $HOME/Desktop/AptioFix_Build:/root/AptioFix_Build --name AptioFixBuild --entrypoint /root/setup.sh initial_build DEBUG
  • Like 3
Link to comment
Share on other sites
jeanba3000
jeanba3000
Posted
Posted

Hello everyone

 

How much time should take the building of AptioFix?

On my little 2010 MacBook Air, it has been running for 8 hours and it is still building the DEBUG version, should I worry or consider as normal processing time considering this machine's capacity?

Link to comment
Share on other sites
Slice
Slice
Posted
Posted

Hello everyone

 

How much time should take the building of AptioFix?

On my little 2010 MacBook Air, it has been running for 8 hours and it is still building the DEBUG version, should I worry or consider as normal processing time considering this machine's capacity?

On my comp #1 it requires 57 seconds. I don't think your book is 200 times slower.

  • Like 2
Link to comment
Share on other sites
vit9696
vit9696
Posted
  • Author
Posted

Hi,

 

I updated the details about boot.efi logging. This time I think I got it right:

http://www.insanelymac.com/forum/topic/331381-aptiomemoryfix/page-7?do=findComment&comment=2572819

 

The missed part in the previous description was bootercfg nvram variable, which allows one to configure boot.efi behaviour just like boot-args do to XNU.

May somebody from Clover team add an interface to it? It will be handy when debugging the issues.

 

Additionally I fixed several issues in AptioMemoryFix, which could have caused boot failures on certain motherboards. Hopefully it works fine for more people now :)

  • Like 10
Link to comment
Share on other sites
Trung_Nguyen
Trung_Nguyen
Posted
Posted

AptioMemoryFix works great on Dell latitude E6230(Native NVRAM works!).

AptioInputFix: Prevented me from enter clover GUI(timeout=0), also Apple's Boot Key combination never works!

Anyway, sometimes, when I reboot, I got a prohibited boot icon. Not sure which one caused it but pretty sure that it caused by one of the driver in AptioFix. Debug version write something like Found 2/3 keys... LoadImage...

Link to comment
Share on other sites
 Share
Go to topic listing
×
×
  • Create New...