HyperDbg/hyperdbg/hyperlog/code/Logging.c

/**
 * @file Logging.c
 * @author Sina Karvandi (sina@hyperdbg.org)
 * @brief Message logging and tracing implementation
 * @details
 * @version 0.1
 * @date 2020-04-11
 *
 * @copyright This project is released under the GNU Public License v3.
 *
 */
#include "pch.h"

/**
 * @brief Checks whether the message tracing operates on vmx-root mode or not
 *
 * @return BOOLEAN
 */
BOOLEAN inline LogCheckVmxOperation()
{
    CHECK_VMX_OPERATION VmxOperationCheck = g_MsgTracingCallbacks.VmxOperationCheck;

    if (VmxOperationCheck == NULL)
    {
        //
        // As the caller didn't defined a checker for vmx operation, we assume
        // that it's not operating on vmx-root
        //
        return FALSE;
    }

    //
    // The user specified a vmx checker
    //
    return VmxOperationCheck();
}

/**
 * @brief Checks whether the immediate sending is needed or not
 *
 * @return BOOLEAN
 */
BOOLEAN inline LogCheckImmediateSend(UINT32 OperationCode)
{
    CHECK_IMMEDIATE_MESSAGE_SENDING ImmediateMessageCheck = g_MsgTracingCallbacks.CheckImmediateMessageSending;

    if (ImmediateMessageCheck == NULL)
    {
        //
        // As the caller didn't defined a checker we assume there is no
        // need to send messages immediately
        //
        return FALSE;
    }

    //
    // The user specified a vmx checker
    //
    return ImmediateMessageCheck(OperationCode);
}

/**
 * @brief Checks whether the immediate sending is needed or not
 * @param OptionalBuffer
 * @param OptionalBufferLength
 * @param OperationCode
 *
 * @return BOOLEAN
 */
BOOLEAN inline LogSendImmediateMessage(CHAR * OptionalBuffer,
                                       UINT32 OptionalBufferLength,
                                       UINT32 OperationCode)
{
    SEND_IMMEDIATE_MESSAGE SendImmediateMessage = g_MsgTracingCallbacks.SendImmediateMessage;

    if (SendImmediateMessage == NULL)
    {
        //
        // As the caller didn't defined a checker we assume there is no
        // need to send messages immediately
        //
        return FALSE;
    }

    //
    // The user specified a vmx checker
    //
    return SendImmediateMessage(OptionalBuffer, OptionalBufferLength, OperationCode);
}

/**
 * @brief Initialize the buffer relating to log message tracing
 * @param MsgTracingCallbacks specify the callbacks
 *
 * @return BOOLEAN
 */
BOOLEAN
LogInitialize(MESSAGE_TRACING_CALLBACKS * MsgTracingCallbacks)
{
    ULONG ProcessorsCount;

    ProcessorsCount = PlatformCpuGetActiveProcessorCount();

    //
    // Initialize buffers for trace message and data messages
    //(we have two buffers one for vmx root and one for vmx non-root)
    //
    g_MessageBufferInformation = PlatformMemAllocateZeroedNonPagedPool(sizeof(LOG_BUFFER_INFORMATION) * 2);

    if (!g_MessageBufferInformation)
    {
        return FALSE; // STATUS_INSUFFICIENT_RESOURCES
    }

    //
    // Allocate g_VmxTempMessage and g_VmxLogMessage
    //
    g_VmxTempMessage = NULL;
    g_VmxTempMessage = PlatformMemAllocateZeroedNonPagedPool(PacketChunkSize * ProcessorsCount);

    if (!g_VmxTempMessage)
    {
        PlatformMemFreePool(g_MessageBufferInformation);
        g_MessageBufferInformation = NULL;
        return FALSE; // STATUS_INSUFFICIENT_RESOURCES
    }

    g_VmxLogMessage = NULL;
    g_VmxLogMessage = PlatformMemAllocateZeroedNonPagedPool(PacketChunkSize * ProcessorsCount);

    if (!g_VmxLogMessage)
    {
        PlatformMemFreePool(g_MessageBufferInformation);
        g_MessageBufferInformation = NULL;

        PlatformMemFreePool(g_VmxTempMessage);
        g_VmxTempMessage = NULL;

        return FALSE; // STATUS_INSUFFICIENT_RESOURCES
    }

    //
    // Initialize the lock for Vmx-root mode (HIGH_IRQL Spinlock)
    //
    g_VmxRootLoggingLock = 0;

    //
    // Allocate buffer for messages and initialize the core buffer information
    //
    for (UINT32 i = 0; i < 2; i++)
    {
        //
        // initialize the lock
        // Actually, only the 0th buffer use this spinlock but let initialize it
        // for both but the second buffer spinlock is useless
        // as we use our custom spinlock
        //
        PlatformSpinlockInitialize(&g_MessageBufferInformation[i].BufferLock);
        PlatformSpinlockInitialize(&g_MessageBufferInformation[i].BufferLockForNonImmMessage);

        //
        // allocate the buffer for regular buffers
        //
        g_MessageBufferInformation[i].BufferStartAddress                   = (UINT64)PlatformMemAllocateNonPagedPool(LogBufferSize);
        g_MessageBufferInformation[i].BufferForMultipleNonImmediateMessage = (UINT64)PlatformMemAllocateNonPagedPool(PacketChunkSize);

        if (!g_MessageBufferInformation[i].BufferStartAddress ||
            !g_MessageBufferInformation[i].BufferForMultipleNonImmediateMessage)
        {
            return FALSE; // STATUS_INSUFFICIENT_RESOURCES
        }

        //
        // allocate the buffer for priority buffers
        //
        g_MessageBufferInformation[i].BufferStartAddressPriority = (UINT64)PlatformMemAllocateNonPagedPool(LogBufferSizePriority);

        if (!g_MessageBufferInformation[i].BufferStartAddressPriority)
        {
            return FALSE; // STATUS_INSUFFICIENT_RESOURCES
        }

        //
        // Zeroing the buffer
        //
        PlatformZeroMemory((PVOID)g_MessageBufferInformation[i].BufferStartAddress, LogBufferSize);
        PlatformZeroMemory((PVOID)g_MessageBufferInformation[i].BufferForMultipleNonImmediateMessage, PacketChunkSize);
        PlatformZeroMemory((PVOID)g_MessageBufferInformation[i].BufferStartAddressPriority, LogBufferSizePriority);

        //
        // Set the end address
        //
        g_MessageBufferInformation[i].BufferEndAddress         = (UINT64)g_MessageBufferInformation[i].BufferStartAddress + LogBufferSize;
        g_MessageBufferInformation[i].BufferEndAddressPriority = (UINT64)g_MessageBufferInformation[i].BufferStartAddressPriority + LogBufferSizePriority;
    }

    //
    // Copy the callbacks into the global callback holder
    //
    PlatformWriteMemory(&g_MsgTracingCallbacks, MsgTracingCallbacks, sizeof(MESSAGE_TRACING_CALLBACKS));

    return TRUE;
}

/**
 * @brief Uninitialize the buffer relating to log message tracing
 *
 * @return VOID
 */
VOID
LogUnInitialize()
{
    //
    // de-allocate buffer for messages and initialize the core buffer information (for vmx-root core)
    //
    for (int i = 0; i < 2; i++)
    {
        //
        // Check if the buffer is allocated or not
        //
        if (g_MessageBufferInformation == NULL64_ZERO)
        {
            continue; // No need to free the buffers
        }

        //
        // Free each buffers
        //
        if (g_MessageBufferInformation[i].BufferStartAddress != NULL64_ZERO)
        {
            PlatformMemFreePool((PVOID)g_MessageBufferInformation[i].BufferStartAddress);
        }

        if (g_MessageBufferInformation[i].BufferStartAddressPriority != NULL64_ZERO)
        {
            PlatformMemFreePool((PVOID)g_MessageBufferInformation[i].BufferStartAddressPriority);
        }

        if (g_MessageBufferInformation[i].BufferForMultipleNonImmediateMessage != NULL64_ZERO)
        {
            PlatformMemFreePool((PVOID)g_MessageBufferInformation[i].BufferForMultipleNonImmediateMessage);
        }
    }

    //
    // de-allocate buffers for trace message and data messages if they are allocated
    //
    if (g_MessageBufferInformation != NULL64_ZERO)
    {
        PlatformMemFreePool((PVOID)g_MessageBufferInformation);
        g_MessageBufferInformation = NULL;
    }
}

/**
 * @brief Checks whether the priority or regular buffer is full or not
 *
 * @param Priority Whether the buffer has priority
 * @return BOOLEAN Returns true if the buffer is full, otherwise, return false
 */
BOOLEAN
LogCallbackCheckIfBufferIsFull(BOOLEAN Priority)
{
    UINT32  Index;
    BOOLEAN IsVmxRoot;
    UINT32  CurrentIndexToWrite         = NULL_ZERO;
    UINT32  CurrentIndexToWritePriority = NULL_ZERO;

    //
    // Check that if we're in vmx root-mode
    //
    IsVmxRoot = LogCheckVmxOperation();

    if (IsVmxRoot)
    {
        //
        // Set the index
        //
        Index = 1;
    }
    else
    {
        //
        // Set the index
        //
        Index = 0;
    }

    //
    // check if the buffer is filled to it's maximum index or not
    //
    if (Priority)
    {
        CurrentIndexToWritePriority = g_MessageBufferInformation[Index].CurrentIndexToWritePriority;

        if (g_MessageBufferInformation[Index].CurrentIndexToWritePriority > MaximumPacketsCapacityPriority - 1)
        {
            //
            // start from the beginning
            //
            CurrentIndexToWritePriority = 0;
        }
    }
    else
    {
        CurrentIndexToWrite = g_MessageBufferInformation[Index].CurrentIndexToWrite;

        if (g_MessageBufferInformation[Index].CurrentIndexToWrite > MaximumPacketsCapacity - 1)
        {
            //
            // start from the beginning
            //
            CurrentIndexToWrite = 0;
        }
    }

    //
    // Compute the start of the buffer header
    //
    BUFFER_HEADER * Header;

    if (Priority)
    {
        Header = (BUFFER_HEADER *)((UINT64)g_MessageBufferInformation[Index].BufferStartAddressPriority + (CurrentIndexToWritePriority * (PacketChunkSize + sizeof(BUFFER_HEADER))));
    }
    else
    {
        Header = (BUFFER_HEADER *)((UINT64)g_MessageBufferInformation[Index].BufferStartAddress + (CurrentIndexToWrite * (PacketChunkSize + sizeof(BUFFER_HEADER))));
    }

    //
    // If the next item is valid, then it means the buffer is full and the next
    // item will replace the previous (not served items)
    //
    return Header->Valid;
}

/**
 * @brief Save buffer to the pool
 *
 * @param OperationCode The operation code that will be send to user mode
 * @param Buffer Buffer to be send to user mode
 * @param BufferLength Length of the buffer
 * @param Priority Whether the buffer has priority
 * @return BOOLEAN Returns true if the buffer successfully set to be
 * send to user mode and false if there was an error
 */
_Use_decl_annotations_
BOOLEAN
LogCallbackSendBuffer(UINT32 OperationCode, PVOID Buffer, UINT32 BufferLength, BOOLEAN Priority)
{
    UINT32  Index;
    BOOLEAN IsVmxRoot;
    KIRQL   OldIRQL = NULL_ZERO;

    if (BufferLength > PacketChunkSize - 1 || BufferLength == 0)
    {
        //
        // We can't save this huge buffer
        //
        return FALSE;
    }

    //
    // Check that if we're in vmx root-mode
    //
    IsVmxRoot = LogCheckVmxOperation();

    //
    // Check if we're connected to remote debugger, send it directly to the debugger
    // and the OPERATION_MANDATORY_DEBUGGEE_BIT should not be set because those operation
    // codes that their MSB are set should be handled locally
    //
    if (LogCheckImmediateSend(OperationCode))
    {
        //
        // if we're in vmx non-root then in order to avoid scheduling we raise the IRQL
        // to DISPATCH_LEVEL because we will get the lock of sending over serial in the
        // next function. In vmx-root RFLAGS.IF is cleared so no interrupt happens and
        // we're safe to get the lock, the same approach is for KeAcquireSpinLock
        //
        if (!IsVmxRoot)
        {
            //
            // vmx non-root
            //
            OldIRQL = PlatformIrqlRaiseToDpcLevel();
        }

        //
        // Kernel debugger is active, we should send the bytes over serial
        //
        LogSendImmediateMessage(
            Buffer,
            BufferLength,
            OperationCode);

        //
        // Release the vmx non-root lock
        //
        if (!IsVmxRoot)
        {
            //
            // vmx non-root
            //
            PlatformIrqlLower(OldIRQL);
        }

        return TRUE;
    }

    //
    // Check if we're in Vmx-root, if it is then we use our customized HIGH_IRQL Spinlock,
    // if not we use the windows spinlock
    //
    if (IsVmxRoot)
    {
        //
        // Set the index
        //
        Index = 1;
        SpinlockLock(&g_VmxRootLoggingLock);
    }
    else
    {
        //
        // Set the index
        //
        Index = 0;

        //
        // Acquire the lock
        //
        PlatformSpinlockAcquire(&g_MessageBufferInformation[Index].BufferLock, &OldIRQL);
    }

    //
    // check if the buffer is filled to it's maximum index or not
    //
    if (Priority)
    {
        if (g_MessageBufferInformation[Index].CurrentIndexToWritePriority > MaximumPacketsCapacityPriority - 1)
        {
            //
            // start from the beginning
            //
            g_MessageBufferInformation[Index].CurrentIndexToWritePriority = 0;
        }
    }
    else
    {
        if (g_MessageBufferInformation[Index].CurrentIndexToWrite > MaximumPacketsCapacity - 1)
        {
            //
            // start from the beginning
            //
            g_MessageBufferInformation[Index].CurrentIndexToWrite = 0;
        }
    }

    //
    // Compute the start of the buffer header
    //
    BUFFER_HEADER * Header;

    if (Priority)
    {
        Header = (BUFFER_HEADER *)((UINT64)g_MessageBufferInformation[Index].BufferStartAddressPriority + (g_MessageBufferInformation[Index].CurrentIndexToWritePriority * (PacketChunkSize + sizeof(BUFFER_HEADER))));
    }
    else
    {
        Header = (BUFFER_HEADER *)((UINT64)g_MessageBufferInformation[Index].BufferStartAddress + (g_MessageBufferInformation[Index].CurrentIndexToWrite * (PacketChunkSize + sizeof(BUFFER_HEADER))));
    }

    //
    // Set the header
    //
    Header->OperationNumber = OperationCode;
    Header->BufferLength    = BufferLength;
    Header->Valid           = TRUE;

    //
    // ******** Now it's time to fill the buffer ********
    //

    //
    // compute the saving index
    //
    PVOID SavingBuffer;

    if (Priority)
    {
        SavingBuffer = (PVOID)((UINT64)g_MessageBufferInformation[Index].BufferStartAddressPriority + (g_MessageBufferInformation[Index].CurrentIndexToWritePriority * (PacketChunkSize + sizeof(BUFFER_HEADER))) + sizeof(BUFFER_HEADER));
    }
    else
    {
        SavingBuffer = (PVOID)((UINT64)g_MessageBufferInformation[Index].BufferStartAddress + (g_MessageBufferInformation[Index].CurrentIndexToWrite * (PacketChunkSize + sizeof(BUFFER_HEADER))) + sizeof(BUFFER_HEADER));
    }

    //
    // Copy the buffer
    //
    PlatformWriteMemory(SavingBuffer, Buffer, BufferLength);

    //
    // Increment the next index to write
    //
    if (Priority)
    {
        g_MessageBufferInformation[Index].CurrentIndexToWritePriority = g_MessageBufferInformation[Index].CurrentIndexToWritePriority + 1;
    }
    else
    {
        g_MessageBufferInformation[Index].CurrentIndexToWrite = g_MessageBufferInformation[Index].CurrentIndexToWrite + 1;
    }

    //
    // check if there is any thread in IRP Pending state, so we can complete their request
    //
    if (g_GlobalNotifyRecord != NULL)
    {
        //
        // there is some threads that needs to be completed
        //

        //
        // set the target pool
        //
        g_GlobalNotifyRecord->CheckVmxRootMessagePool = IsVmxRoot;

        //
        // Insert dpc to queue
        //
        PlatformDpcInsertQueueDpc(&g_GlobalNotifyRecord->Dpc, g_GlobalNotifyRecord, NULL);

        //
        // set notify routine to null
        //
        g_GlobalNotifyRecord = NULL;
    }

    //
    // Check if we're in Vmx-root, if it is then we use our customized HIGH_IRQL Spinlock,
    // if not we use the windows spinlock
    //
    if (IsVmxRoot)
    {
        SpinlockUnlock(&g_VmxRootLoggingLock);
    }
    else
    {
        //
        // Release the lock
        //
        PlatformSpinlockRelease(&g_MessageBufferInformation[Index].BufferLock, OldIRQL);
    }

    return TRUE;
}

/**
 * @brief Mark all buffers as read
 * @details Priority buffers won't be set as read
 *
 * @param IsVmxRoot Determine whether you want to read vmx root buffer or vmx non root buffer
 * @return UINT32 return count of messages that set to invalid
 */
UINT32
LogMarkAllAsRead(BOOLEAN IsVmxRoot)
{
    UINT32 Index;
    UINT32 ResultsOfBuffersSetToRead = 0;
    KIRQL  OldIRQL                   = NULL_ZERO;

    //
    // Check if we're in Vmx-root, if it is then we use our customized HIGH_IRQL Spinlock,
    // if not we use the windows spinlock
    //
    if (IsVmxRoot)
    {
        //
        // Set the index
        //
        Index = 1;

        //
        // Acquire the lock
        //
        SpinlockLock(&g_VmxRootLoggingLock);
    }
    else
    {
        //
        // Set the index
        //
        Index = 0;

        //
        // Acquire the lock
        //
        PlatformSpinlockAcquire(&g_MessageBufferInformation[Index].BufferLock, &OldIRQL);
    }

    //
    // We have iterate through the all indexes
    //
    for (SIZE_T i = 0; i < MaximumPacketsCapacity; i++)
    {
        //
        // Compute the current buffer to read
        //
        BUFFER_HEADER * Header = (BUFFER_HEADER *)((UINT64)g_MessageBufferInformation[Index].BufferStartAddress +
                                                   (g_MessageBufferInformation[Index].CurrentIndexToSend *
                                                    (PacketChunkSize + sizeof(BUFFER_HEADER))));

        if (!Header->Valid)
        {
            //
            // there is nothing to send
            //

            //
            // Check if we're in Vmx-root, if it is then we use our customized HIGH_IRQL Spinlock,
            // if not we use the windows spinlock
            //
            if (IsVmxRoot)
            {
                SpinlockUnlock(&g_VmxRootLoggingLock);
            }
            else
            {
                //
                // Release the lock
                //
                PlatformSpinlockRelease(&g_MessageBufferInformation[Index].BufferLock, OldIRQL);
            }

            return ResultsOfBuffersSetToRead;
        }

        //
        // If we reached here, means that there is sth to send
        //
        ResultsOfBuffersSetToRead++;

        //
        // Second, save the buffer contents
        //
        PVOID SendingBuffer = (PVOID)((UINT64)g_MessageBufferInformation[Index].BufferStartAddress + (g_MessageBufferInformation[Index].CurrentIndexToSend * (PacketChunkSize + sizeof(BUFFER_HEADER))) + sizeof(BUFFER_HEADER));

        //
        // Finally, set the current index to invalid as we sent it
        //
        Header->Valid = FALSE;

        //
        // Last step is to clear the current buffer (we can't do it once when CurrentIndexToSend is zero because
        // there might be multiple messages on the start of the queue that didn't read yet)
        // we don't free the header
        //
        PlatformZeroMemory(SendingBuffer, Header->BufferLength);

        //
        // Check to see whether we passed the index or not
        //
        if (g_MessageBufferInformation[Index].CurrentIndexToSend > MaximumPacketsCapacity - 2)
        {
            g_MessageBufferInformation[Index].CurrentIndexToSend = 0;
        }
        else
        {
            //
            // Increment the next index to read
            //
            g_MessageBufferInformation[Index].CurrentIndexToSend = g_MessageBufferInformation[Index].CurrentIndexToSend + 1;
        }
    }

    //
    // Check if we're in Vmx-root, if it is then we use our customized HIGH_IRQL Spinlock,
    // if not we use the windows spinlock
    //
    if (IsVmxRoot)
    {
        SpinlockUnlock(&g_VmxRootLoggingLock);
    }
    else
    {
        //
        // Release the lock
        //
        PlatformSpinlockRelease(&g_MessageBufferInformation[Index].BufferLock, OldIRQL);
    }

    return ResultsOfBuffersSetToRead;
}

/**
 * @brief Attempt to read the buffer
 *
 * @param IsVmxRoot Determine whether you want to read vmx root buffer or vmx non root buffer
 * @param BufferToSaveMessage Target buffer to save the message
 * @param ReturnedLength The actual length of the buffer that this function used it
 * @return BOOLEAN return of this function shows whether the read was successful
 * or not (e.g FALSE shows there's no new buffer available.)
 */
BOOLEAN
LogReadBuffer(BOOLEAN IsVmxRoot, PVOID BufferToSaveMessage, UINT32 * ReturnedLength)
{
    UINT32  Index;
    BOOLEAN PriorityMessageIsAvailable = FALSE;
    KIRQL   OldIRQL                    = NULL_ZERO;

    //
    // Check if we're in Vmx-root, if it is then we use our customized HIGH_IRQL Spinlock,
    // if not we use the windows spinlock
    //
    if (IsVmxRoot)
    {
        //
        // Set the index
        //
        Index = 1;

        //
        // Acquire the lock
        //
        SpinlockLock(&g_VmxRootLoggingLock);
    }
    else
    {
        //
        // Set the index
        //
        Index = 0;

        //
        // Acquire the lock
        //
        PlatformSpinlockAcquire(&g_MessageBufferInformation[Index].BufferLock, &OldIRQL);
    }

    //
    // Compute the current buffer to read
    //
    BUFFER_HEADER * Header;

    //
    // Check for priority message
    //
    Header = (BUFFER_HEADER *)((UINT64)g_MessageBufferInformation[Index].BufferStartAddressPriority + (g_MessageBufferInformation[Index].CurrentIndexToSendPriority * (PacketChunkSize + sizeof(BUFFER_HEADER))));

    if (!Header->Valid)
    {
        //
        // Check for regular message
        //
        Header = (BUFFER_HEADER *)((UINT64)g_MessageBufferInformation[Index].BufferStartAddress + (g_MessageBufferInformation[Index].CurrentIndexToSend * (PacketChunkSize + sizeof(BUFFER_HEADER))));

        if (!Header->Valid)
        {
            //
            // there is nothing to send
            //

            //
            // Check if we're in Vmx-root, if it is then we use our customized HIGH_IRQL Spinlock,
            // if not we use the windows spinlock
            //
            if (IsVmxRoot)
            {
                SpinlockUnlock(&g_VmxRootLoggingLock);
            }
            else
            {
                //
                // Release the lock
                //
                PlatformSpinlockRelease(&g_MessageBufferInformation[Index].BufferLock, OldIRQL);
            }

            return FALSE;
        }
    }
    else
    {
        PriorityMessageIsAvailable = TRUE;
    }

    //
    // If we reached here, means that there is sth to send
    //

    //
    // First copy the header
    //
    PlatformWriteMemory(BufferToSaveMessage, &Header->OperationNumber, sizeof(UINT32));

    //
    // Second, save the buffer contents
    //
    PVOID SendingBuffer;

    if (PriorityMessageIsAvailable)
    {
        SendingBuffer = (PVOID)((UINT64)g_MessageBufferInformation[Index].BufferStartAddressPriority + (g_MessageBufferInformation[Index].CurrentIndexToSendPriority * (PacketChunkSize + sizeof(BUFFER_HEADER))) + sizeof(BUFFER_HEADER));
    }
    else
    {
        SendingBuffer = (PVOID)((UINT64)g_MessageBufferInformation[Index].BufferStartAddress + (g_MessageBufferInformation[Index].CurrentIndexToSend * (PacketChunkSize + sizeof(BUFFER_HEADER))) + sizeof(BUFFER_HEADER));
    }

    //
    // Because we want to pass the header of usermode header
    //
    PVOID SavingAddress = (PVOID)((UINT64)BufferToSaveMessage + sizeof(UINT32));

    PlatformWriteMemory(SavingAddress, SendingBuffer, Header->BufferLength);

#if ShowMessagesOnDebugger

    //
    // Means that show just messages
    //
    if (Header->OperationNumber <= OPERATION_LOG_NON_IMMEDIATE_MESSAGE)
    {
        //
        // We're in Dpc level here so it's safe to use DbgPrint
        // DbgPrint limitation is 512 Byte
        //
        if (Header->BufferLength > DbgPrintLimitation)
        {
            for (SIZE_T i = 0; i <= Header->BufferLength / DbgPrintLimitation; i++)
            {
                if (i != 0)
                {
                    PlatformDbgPrint("%s", (CHAR *)((UINT64)SendingBuffer + (DbgPrintLimitation * i) - 2));
                }
                else
                {
                    PlatformDbgPrint("%s", (CHAR *)((UINT64)SendingBuffer + (DbgPrintLimitation * i)));
                }
            }
        }
        else
        {
            PlatformDbgPrint("%s", (CHAR *)SendingBuffer);
        }
    }
#endif

    //
    // Finally, set the current index to invalid as we sent it
    //
    Header->Valid = FALSE;

    //
    // Set the length to show as the ReturnedByted in usermode ioctl function + size of header
    //
    *ReturnedLength = Header->BufferLength + sizeof(UINT32);

    //
    // Last step is to clear the current buffer (we can't do it once when CurrentIndexToSend is zero because
    // there might be multiple messages on the start of the queue that didn't read yet)
    // we don't free the header
    //
    PlatformZeroMemory(SendingBuffer, Header->BufferLength);

    if (PriorityMessageIsAvailable)
    {
        //
        // Check to see whether we passed the index or not
        //
        if (g_MessageBufferInformation[Index].CurrentIndexToSendPriority > MaximumPacketsCapacityPriority - 2)
        {
            g_MessageBufferInformation[Index].CurrentIndexToSendPriority = 0;
        }
        else
        {
            //
            // Increment the next index to read
            //
            g_MessageBufferInformation[Index].CurrentIndexToSendPriority = g_MessageBufferInformation[Index].CurrentIndexToSendPriority + 1;
        }
    }
    else
    {
        //
        // Check to see whether we passed the index or not
        //
        if (g_MessageBufferInformation[Index].CurrentIndexToSend > MaximumPacketsCapacity - 2)
        {
            g_MessageBufferInformation[Index].CurrentIndexToSend = 0;
        }
        else
        {
            //
            // Increment the next index to read
            //
            g_MessageBufferInformation[Index].CurrentIndexToSend = g_MessageBufferInformation[Index].CurrentIndexToSend + 1;
        }
    }

    //
    // Check if we're in Vmx-root, if it is then we use our customized HIGH_IRQL Spinlock,
    // if not we use the windows spinlock
    //
    if (IsVmxRoot)
    {
        SpinlockUnlock(&g_VmxRootLoggingLock);
    }
    else
    {
        //
        // Release the lock
        //
        PlatformSpinlockRelease(&g_MessageBufferInformation[Index].BufferLock, OldIRQL);
    }

    return TRUE;
}

/**
 * @brief Check if new message is available or not
 *
 * @param IsVmxRoot Check vmx root pool for message or check vmx non root pool
 * @param Priority Whether the buffer has priority
 *
 * @return BOOLEAN return of this function shows whether the read was successful or not
 * (e.g FALSE shows there's no new buffer available.)
 */
BOOLEAN
LogCheckForNewMessage(BOOLEAN IsVmxRoot, BOOLEAN Priority)
{
    UINT32 Index;

    if (IsVmxRoot)
    {
        Index = 1;
    }
    else
    {
        Index = 0;
    }

    //
    // Compute the current buffer to read
    //
    BUFFER_HEADER * Header;

    if (Priority)
    {
        Header = (BUFFER_HEADER *)((UINT64)g_MessageBufferInformation[Index].BufferStartAddressPriority + (g_MessageBufferInformation[Index].CurrentIndexToSendPriority * (PacketChunkSize + sizeof(BUFFER_HEADER))));
    }
    else
    {
        Header = (BUFFER_HEADER *)((UINT64)g_MessageBufferInformation[Index].BufferStartAddress + (g_MessageBufferInformation[Index].CurrentIndexToSend * (PacketChunkSize + sizeof(BUFFER_HEADER))));
    }

    if (!Header->Valid)
    {
        //
        // there is nothing to send
        //
        return FALSE;
    }

    //
    // If we reached here, means that there is sth to send
    //
    return TRUE;
}

/**
 * @brief Prepare a printf-style message mapping and send string messages
 * and tracing for logging and monitoring
 *
 * @param OperationCode Optional operation code
 * @param IsImmediateMessage Should be sent immediately
 * @param ShowCurrentSystemTime Show system-time
 * @param Priority Whether the message has priority
 * @param Fmt Message format-string
 * @param ...
 * @return BOOLEAN if it was successful then return TRUE, otherwise returns FALSE
 */
BOOLEAN
LogCallbackPrepareAndSendMessageToQueueWrapper(UINT32       OperationCode,
                                               BOOLEAN      IsImmediateMessage,
                                               BOOLEAN      ShowCurrentSystemTime,
                                               BOOLEAN      Priority,
                                               const CHAR * Fmt,
                                               va_list      ArgList)
{
    INT32   SprintfResult;
    SIZE_T  WrittenSize;
    BOOLEAN IsVmxRootMode;
    BOOLEAN Result         = FALSE; // by default, we assume error happens
    CHAR *  LogMessage     = NULL;
    CHAR *  TempMessage    = NULL;
    CHAR    TimeBuffer[20] = {0};
    ULONG   CurrentCore    = PlatformCpuGetCurrentProcessorNumber();

    //
    // Set Vmx State
    //
    IsVmxRootMode = LogCheckVmxOperation();

    //
    // Set the buffer here, we avoid use stack (local variables) because stack might growth
    // and be problematic
    //
    if (IsVmxRootMode)
    {
        LogMessage  = &g_VmxLogMessage[CurrentCore * PacketChunkSize];
        TempMessage = &g_VmxTempMessage[CurrentCore * PacketChunkSize];
    }
    else
    {
        //
        // To avoid buffer collision and buffer re-writing in VMX non-root, allocate pool
        //
        LogMessage = PlatformMemAllocateNonPagedPool(PacketChunkSize);

        if (LogMessage == NULL)
        {
            //
            // Insufficient space
            //
            return FALSE;
        }
        TempMessage = PlatformMemAllocateNonPagedPool(PacketChunkSize);

        if (TempMessage == NULL)
        {
            //
            // Insufficient space
            //
            PlatformMemFreePool(LogMessage);
            return FALSE;
        }
    }

    if (ShowCurrentSystemTime)
    {
        //
        // It's actually not necessary to use -1 but because user-mode code might assume a null-terminated buffer so
        // it's better to use - 1
        //

        //
        // We won't use this because we can't use in any IRQL
        // Status = RtlStringCchVPrintfA(TempMessage, PacketChunkSize - 1, Fmt, ArgList);
        //
        SprintfResult = vsprintf_s(TempMessage, PacketChunkSize - 1, Fmt, ArgList);

        //
        // Check if the buffer passed the limit
        //
        if (SprintfResult == -1)
        {
            //
            // Probably the buffer is large that we can't store it
            //
            goto FreeBufferAndReturn;
        }

        //
        // Fill the above with timer
        //
        TIME_FIELDS   TimeFields;
        LARGE_INTEGER SystemTime, LocalTime;
        PlatformTimeQuerySystemTime(&SystemTime);
        PlatformTimeConvertToLocalTime(&SystemTime, &LocalTime);
        PlatformTimeConvertToTimeFields(&LocalTime, &TimeFields);

        //
        // We won't use this because we can't use in any IRQL
        // Status = RtlStringCchPrintfA(TimeBuffer, RTL_NUMBER_OF(TimeBuffer),
        //	"%02hd:%02hd:%02hd.%03hd", TimeFields.Hour,
        //	TimeFields.Minute, TimeFields.Second,
        //	TimeFields.Milliseconds);
        //
        //
        // Append time with previous message
        //
        // Status = RtlStringCchPrintfA(LogMessage, PacketChunkSize - 1, "(%s)\t %s", TimeBuffer, TempMessage);
        //

        //
        // this function probably run without error, so there is no need to check the return value
        //
        sprintf_s(TimeBuffer, RTL_NUMBER_OF(TimeBuffer), "%02hd:%02hd:%02hd.%03hd", TimeFields.Hour, TimeFields.Minute, TimeFields.Second, TimeFields.Milliseconds);

        //
        // Append time with previous message
        //
        SprintfResult = sprintf_s(LogMessage, PacketChunkSize - 1, "(%s - core : %d - vmx-root? %s)\t %s", TimeBuffer, CurrentCore, IsVmxRootMode ? "yes" : "no", TempMessage);

        //
        // Check if the buffer passed the limit
        //
        if (SprintfResult == -1)
        {
            //
            // Probably the buffer is large that we can't store it
            //
            goto FreeBufferAndReturn;
        }
    }
    else
    {
        //
        // It's actually not necessary to use -1 but because user-mode code might assume a null-terminated buffer so
        // it's better to use - 1
        //

        //
        // We won't use this because we can't use in any IRQL
        // Status = RtlStringCchVPrintfA(LogMessage, PacketChunkSize - 1, Fmt, ArgList);
        //
        SprintfResult = vsprintf_s(LogMessage, PacketChunkSize - 1, Fmt, ArgList);

        //
        // Check if the buffer passed the limit
        //
        if (SprintfResult == -1)
        {
            //
            // Probably the buffer is large that we can't store it
            //
            goto FreeBufferAndReturn;
        }
    }

    //
    // Use std function because they can be run in any IRQL
    // RtlStringCchLengthA(LogMessage, PacketChunkSize - 1, &WrittenSize);
    //
    WrittenSize = strnlen_s(LogMessage, PacketChunkSize - 1);

    if (LogMessage[0] == '\0')
    {
        //
        // nothing to write
        //
        goto FreeBufferAndReturn;
    }

    //
    // Send the prepared buffer (with no priority)
    //
    Result = LogCallbackSendMessageToQueue(OperationCode, IsImmediateMessage, LogMessage, (UINT32)WrittenSize, Priority);

FreeBufferAndReturn:

    if (!IsVmxRootMode)
    {
        PlatformMemFreePool(LogMessage);
        PlatformMemFreePool(TempMessage);
    }

    return Result;
}

/**
 * @brief Prepare a printf-style message mapping and send string messages
 * and tracing for logging and monitoring
 *
 * @param OperationCode Optional operation code
 * @param IsImmediateMessage Should be sent immediately
 * @param ShowCurrentSystemTime Show system-time
 * @param Priority Whether the message has priority
 * @param Fmt Message format-string
 * @param ...
 * @return BOOLEAN if it was successful then return TRUE, otherwise returns FALSE
 */
BOOLEAN
LogCallbackPrepareAndSendMessageToQueue(UINT32       OperationCode,
                                        BOOLEAN      IsImmediateMessage,
                                        BOOLEAN      ShowCurrentSystemTime,
                                        BOOLEAN      Priority,
                                        const CHAR * Fmt,
                                        ...)
{
    va_list ArgList;
    BOOLEAN Result;

    va_start(ArgList, Fmt);

    Result = LogCallbackPrepareAndSendMessageToQueueWrapper(OperationCode,
                                                            IsImmediateMessage,
                                                            ShowCurrentSystemTime,
                                                            Priority,
                                                            Fmt,
                                                            ArgList);

    va_end(ArgList);

    return Result;
}

/**
 * @brief Send string messages and tracing for logging and monitoring
 *
 * @param OperationCode Optional operation code
 * @param IsImmediateMessage Should be sent immediately
 * @param LogMessage Link of message buffer
 * @param BufferLen Length of buffer
 * @param Priority Whether the buffer has priority
 *
 * @return BOOLEAN if it was successful then return TRUE, otherwise returns FALSE
 */
BOOLEAN
LogCallbackSendMessageToQueue(UINT32 OperationCode, BOOLEAN IsImmediateMessage, CHAR * LogMessage, UINT32 BufferLen, BOOLEAN Priority)
{
    BOOLEAN Result;
    UINT32  Index;
    BOOLEAN IsVmxRootMode;
    KIRQL   OldIRQL = NULL_ZERO;

    //
    // Set Vmx State
    //
    IsVmxRootMode = LogCheckVmxOperation();

#if UseWPPTracing

    if (OperationCode == OPERATION_LOG_INFO_MESSAGE)
    {
        HypervisorTraceLevelMessage(
            TRACE_LEVEL_INFORMATION, // ETW Level defined in evntrace.h
            HVFS_LOG_INFO,
            "%s", // Flag defined in WPP_CONTROL_GUIDS
            LogMessage);
    }
    else if (OperationCode == OPERATION_LOG_WARNING_MESSAGE)
    {
        HypervisorTraceLevelMessage(
            TRACE_LEVEL_WARNING, // ETW Level defined in evntrace.h
            HVFS_LOG_WARNING,
            "%s", // Flag defined in WPP_CONTROL_GUIDS
            LogMessage);
    }
    else if (OperationCode == OPERATION_LOG_ERROR_MESSAGE)
    {
        HypervisorTraceLevelMessage(
            TRACE_LEVEL_ERROR, // ETW Level defined in evntrace.h
            HVFS_LOG_ERROR,
            "%s", // Flag defined in WPP_CONTROL_GUIDS
            LogMessage);
    }
    else
    {
        HypervisorTraceLevelMessage(
            TRACE_LEVEL_NONE, // ETW Level defined in evntrace.h
            HVFS_LOG,
            "%s", // Flag defined in WPP_CONTROL_GUIDS
            LogMessage);
    }

#else
    if (IsImmediateMessage)
    {
        return LogCallbackSendBuffer(OperationCode, LogMessage, BufferLen, Priority);
    }
    else
    {
        //
        // Check if we're in Vmx-root, if it is then we use our customized HIGH_IRQL Spinlock,
        // if not we use the windows spinlock
        //
        if (IsVmxRootMode)
        {
            //
            // Set the index
            //
            Index = 1;
            SpinlockLock(&g_VmxRootLoggingLockForNonImmBuffers);
        }
        else
        {
            //
            // Set the index
            //
            Index = 0;

            //
            // Acquire the lock
            //
            PlatformSpinlockAcquire(&g_MessageBufferInformation[Index].BufferLockForNonImmMessage, &OldIRQL);
        }
        //
        // Set the result to True
        //
        Result = TRUE;

        //
        // If log message WrittenSize is above the buffer then we have to send the previous buffer
        //
        if ((g_MessageBufferInformation[Index].CurrentLengthOfNonImmBuffer + BufferLen) > PacketChunkSize - 1 && g_MessageBufferInformation[Index].CurrentLengthOfNonImmBuffer != 0)
        {
            //
            // Send the previous buffer (non-immediate message),
            // accumulated messages don't have priority
            //
            Result = LogCallbackSendBuffer(OPERATION_LOG_NON_IMMEDIATE_MESSAGE,
                                           (PVOID)g_MessageBufferInformation[Index].BufferForMultipleNonImmediateMessage,
                                           g_MessageBufferInformation[Index].CurrentLengthOfNonImmBuffer,
                                           FALSE);

            //
            // Free the immediate buffer
            //
            g_MessageBufferInformation[Index].CurrentLengthOfNonImmBuffer = 0;
            PlatformZeroMemory((PVOID)g_MessageBufferInformation[Index].BufferForMultipleNonImmediateMessage, PacketChunkSize);
        }

        //
        // We have to save the message
        //
        PlatformWriteMemory((PVOID)(g_MessageBufferInformation[Index].BufferForMultipleNonImmediateMessage +
                                    g_MessageBufferInformation[Index].CurrentLengthOfNonImmBuffer),
                            LogMessage,
                            BufferLen);

        //
        // add the length
        //
        g_MessageBufferInformation[Index].CurrentLengthOfNonImmBuffer += BufferLen;

        // Check if we're in Vmx-root, if it is then we use our customized HIGH_IRQL Spinlock,
        // if not we use the windows spinlock
        //
        if (IsVmxRootMode)
        {
            SpinlockUnlock(&g_VmxRootLoggingLockForNonImmBuffers);
        }
        else
        {
            //
            // Release the lock
            //
            PlatformSpinlockRelease(&g_MessageBufferInformation[Index].BufferLockForNonImmMessage, OldIRQL);
        }

        return Result;
    }
#endif
}

/**
 * @brief Complete the IRP in IRP Pending state and fill the usermode buffers with pool data
 *
 * @param Dpc
 * @param DeferredContext
 * @param SystemArgument1
 * @param SystemArgument2
 * @return VOID
 */
VOID
LogNotifyUsermodeCallback(PKDPC Dpc, PVOID DeferredContext, PVOID SystemArgument1, PVOID SystemArgument2)
{
    PNOTIFY_RECORD NotifyRecord;
    PIRP           Irp;
    UINT32         Length;

    UNREFERENCED_PARAMETER(Dpc);
    UNREFERENCED_PARAMETER(SystemArgument1);
    UNREFERENCED_PARAMETER(SystemArgument2);

    NotifyRecord = DeferredContext;

    ASSERT(NotifyRecord != NULL); // can't be NULL
    _Analysis_assume_(NotifyRecord != NULL);

    switch (NotifyRecord->Type)
    {
    case IRP_BASED:
        Irp = NotifyRecord->Message.PendingIrp;

        if (Irp != NULL)
        {
            PCHAR              OutBuff;       // pointer to output buffer
            ULONG              InBuffLength;  // Input buffer length
            ULONG              OutBuffLength; // Output buffer length
            PIO_STACK_LOCATION IrpSp;

            //
            // Make suree that concurrent calls to notify function never occurs
            //
            if (!(Irp->CurrentLocation <= Irp->StackCount + 1))
            {
                PlatformDbgPrint("Err, probably two or more functions called DPC for an object");
                return;
            }

            IrpSp         = PlatformIoGetCurrentIrpStackLocation(Irp);
            InBuffLength  = IrpSp->Parameters.DeviceIoControl.InputBufferLength;
            OutBuffLength = IrpSp->Parameters.DeviceIoControl.OutputBufferLength;

            if (!InBuffLength || !OutBuffLength)
            {
                Irp->IoStatus.Status = STATUS_INVALID_PARAMETER;
                PlatformIoCompleteRequest(Irp, IO_NO_INCREMENT);
                break;
            }

            //
            // Check again that SystemBuffer is not null
            //
            if (!Irp->AssociatedIrp.SystemBuffer)
            {
                //
                // Buffer is invalid
                //
                return;
            }

            OutBuff = Irp->AssociatedIrp.SystemBuffer;
            Length  = 0;

            //
            // Read Buffer might be empty (nothing to send)
            //
            if (!LogReadBuffer(NotifyRecord->CheckVmxRootMessagePool, OutBuff, &Length))
            {
                //
                // we have to return here as there is nothing to send here
                //
                Irp->IoStatus.Status = STATUS_INVALID_PARAMETER;
                PlatformIoCompleteRequest(Irp, IO_NO_INCREMENT);
                break;
            }

            Irp->IoStatus.Information = Length;

            Irp->IoStatus.Status = STATUS_SUCCESS;
            PlatformIoCompleteRequest(Irp, IO_NO_INCREMENT);
        }
        break;

    case EVENT_BASED:
        //
        // Signal the Event created in user-mode.
        //
        PlatformEventSet(NotifyRecord->Message.Event, 0, FALSE);

        //
        // Dereference the object as we are done with it.
        //
        PlatformObjectDereference(NotifyRecord->Message.Event);

        break;

    default:
        ASSERT(FALSE);
        break;
    }

    if (NotifyRecord != NULL)
    {
        PlatformMemFreePool(NotifyRecord);
    }
}

/**
 * @brief Register a new IRP Pending thread which listens for new buffers
 *
 * @param TargetIrp
 * @param Status
 *
 * @return BOOLEAN
 */
BOOLEAN
LogRegisterIrpBasedNotification(PVOID TargetIrp, LONG * Status)
{
    PNOTIFY_RECORD          NotifyRecord;
    PIO_STACK_LOCATION      IrpStack;
    PREGISTER_NOTIFY_BUFFER RegisterEvent;
    PIRP                    Irp = (PIRP)TargetIrp;

    //
    // check if current core has another thread with pending IRP,
    // if no then put the current thread to pending
    // otherwise return and complete thread with STATUS_SUCCESS as
    // there is another thread waiting for message
    //

    if (g_GlobalNotifyRecord == NULL)
    {
        IrpStack      = PlatformIoGetCurrentIrpStackLocation(Irp);
        RegisterEvent = (PREGISTER_NOTIFY_BUFFER)Irp->AssociatedIrp.SystemBuffer;

        //
        // Allocate a record and save all the event context
        //
        NotifyRecord = PlatformMemAllocateNonPagedPoolWithQuota(sizeof(NOTIFY_RECORD));

        if (NULL == NotifyRecord)
        {
            *Status = (LONG)STATUS_INSUFFICIENT_RESOURCES;
            return FALSE;
        }

        NotifyRecord->Type               = IRP_BASED;
        NotifyRecord->Message.PendingIrp = Irp;

        PlatformDpcInitialize(&NotifyRecord->Dpc,        // Dpc
                              LogNotifyUsermodeCallback, // DeferredRoutine
                              NotifyRecord               // DeferredContext
        );

        PlatformIoMarkIrpPending(Irp);

        //
        // check for new message (for both Vmx-root mode or Vmx non root-mode)
        // First, we check for priority messages in both buffers then we check
        // for regular messages
        //
        if (LogCheckForNewMessage(FALSE, TRUE))
        {
            //
            // check vmx non-root (priority buffers)
            //
            NotifyRecord->CheckVmxRootMessagePool = FALSE;

            //
            // Insert dpc to queue
            //
            PlatformDpcInsertQueueDpc(&NotifyRecord->Dpc, NotifyRecord, NULL);
        }
        else if (LogCheckForNewMessage(TRUE, TRUE))
        {
            //
            // check vmx root (priority buffers)
            //
            NotifyRecord->CheckVmxRootMessagePool = TRUE;
            //
            // Insert dpc to queue
            //
            PlatformDpcInsertQueueDpc(&NotifyRecord->Dpc, NotifyRecord, NULL);
        }
        else if (LogCheckForNewMessage(FALSE, FALSE))
        {
            //
            // check vmx non-root
            //
            NotifyRecord->CheckVmxRootMessagePool = FALSE;

            //
            // Insert dpc to queue
            //
            PlatformDpcInsertQueueDpc(&NotifyRecord->Dpc, NotifyRecord, NULL);
        }
        else if (LogCheckForNewMessage(TRUE, FALSE))
        {
            //
            // check vmx root
            //
            NotifyRecord->CheckVmxRootMessagePool = TRUE;
            //
            // Insert dpc to queue
            //
            PlatformDpcInsertQueueDpc(&NotifyRecord->Dpc, NotifyRecord, NULL);
        }
        else
        {
            //
            // Set the notify routine to the global structure
            //
            g_GlobalNotifyRecord = NotifyRecord;
        }
        //
        // We will return pending as we have marked the IRP pending
        //

        *Status = (LONG)STATUS_PENDING;
        return TRUE;
    }
    else
    {
        *Status = (LONG)STATUS_SUCCESS;
        return TRUE;
    }
}

/**
 * @brief Create an event-based usermode notifying mechanism
 *
 * @param TargetIrp
 * @return BOOLEAN
 */
BOOLEAN
LogRegisterEventBasedNotification(PVOID TargetIrp)
{
    PNOTIFY_RECORD          NotifyRecord;
    NTSTATUS                Status;
    PIO_STACK_LOCATION      IrpStack;
    PREGISTER_NOTIFY_BUFFER RegisterEvent;
    PIRP                    Irp = (PIRP)TargetIrp;

    IrpStack      = PlatformIoGetCurrentIrpStackLocation(Irp);
    RegisterEvent = (PREGISTER_NOTIFY_BUFFER)Irp->AssociatedIrp.SystemBuffer;

    //
    // Allocate a record and save all the event context
    //
    NotifyRecord = PlatformMemAllocateNonPagedPoolWithQuota(sizeof(NOTIFY_RECORD));

    if (NULL == NotifyRecord)
    {
        PlatformDbgPrint("Err, unable to allocate memory for notify record\n");
        return FALSE;
    }

    NotifyRecord->Type = EVENT_BASED;

    PlatformDpcInitialize(&NotifyRecord->Dpc,        // Dpc
                          LogNotifyUsermodeCallback, // DeferredRoutine
                          NotifyRecord               // DeferredContext
    );

    //
    // Get the object pointer from the handle
    // Note we must be in the context of the process that created the handle
    //
    Status = PlatformObjectReferenceByHandle(RegisterEvent->hEvent,
                                             SYNCHRONIZE | EVENT_MODIFY_STATE,
                                             *ExEventObjectType,
                                             Irp->RequestorMode,
                                             &NotifyRecord->Message.Event,
                                             NULL);

    if (!NT_SUCCESS(Status))
    {
        PlatformDbgPrint("Err, unable to reference user mode event object, status = 0x%x\n", Status);
        PlatformMemFreePool(NotifyRecord);
        return FALSE;
    }

    //
    // Insert dpc to the queue
    //
    PlatformDpcInsertQueueDpc(&NotifyRecord->Dpc, NotifyRecord, NULL);

    return TRUE;
}