I seem to have some memory corruption in my processing of printing events to the system event log.
I say “seem” since IoWriteErrorLogEntry is allocated by the kernel, and I cannot start a machine where Special Pool is running on all drivers (the machine is slower than Windows 10 on a Pentium 2 with 2MB of RAM). And the system is not exhibiting issues without the routine which logs to the system event log.
Are these assumption correct:
- Maximum size of an event log entry (allocated by IoAllocateErrorLogEntry) is 240 bytes? (EVENT_LOG_MAXIMUM_SIZE)
- If there is only one string, and DumpData is not required, the string can be placed at FIELD_OFFSET(IO_ERROR_LOG_PACKET, DumpData)? (this seems to be the case, as I see the correct data in the event log, and saw the same in the only samples I found anywhere)
- Max. size of such a string (if only one is present) is EVENT_LOG_MAXIMUM_SIZE - FIELD_OFFSET(IO_ERROR_LOG_PACKET) BYTES?
- The string must include a NULL character, and that NULL char is included in the above limit?
If the above is right, is anyone seeing any issues with the below code:
{
va_list args;
NTSTATUS ntRes;
size_t dwLen = 0, dwFullLen;
PWCHAR lpBuffer = NULL,
lpLogBuffer = NULL;
PIO_ERROR_LOG_PACKET lpEntry = NULL;
LONG dwID = InterlockedIncrement(&dwLogEvent) % 100;
va_start(args, Format);
lpBuffer = OFS_AllocateDirInfoBuffer();
if(!lpBuffer)
{
DbgPrint("OFS: Memory allocation failed during AFF_LogPrint call.\n");
goto Cleanup;
}
if(bDbgBreak)
{
DbgBreakPoint();
bDbgBreak = FALSE;
}
// lpBuffer has dwDirectoryBufferList (65536) charachters. We can use part of it to print the string,
// and the rest to print partial string of max (ERROR_LOG_MAXIMUM_SIZE - sizeof(IO_ERROR_LOG_PACKET))
// / sizeof(WCHAR) characters, which we send to the event log. We save 128 characters for extra use.
ntRes = RtlStringCchVPrintfW(lpBuffer,
dwDirectoryBufferList / sizeof(WCHAR),
Format,
args);
if(!NT_SUCCESS(ntRes) &&
(ntRes != STATUS_BUFFER_OVERFLOW))
{
DbgPrint("OFS: Error 0x%x has occurred during RtlStringCchVPrintfW call.\n", ntRes);
goto Cleanup;
}
ntRes = RtlStringCchLengthW(lpBuffer,
dwDirectoryBufferList / sizeof(WCHAR),
&dwFullLen);
if(!NT_SUCCESS(ntRes))
{
DbgPrint("OFS: Error 0x%x has occurred during RtlStringCchLengthW call.\n", ntRes);
goto Cleanup;
}
// Now we need to divide the string into substrings which can fit into the error log entry buffers.
lpLogBuffer = lpBuffer;
while(dwFullLen)
{
lpEntry = IoAllocateErrorLogEntry(lpGlobalDriver,
ERROR_LOG_MAXIMUM_SIZE);
if(!lpEntry)
{
// There is no point in trying to write an event log entry when an error occurs during
// allocation of an event log entry, so we DbgPrint instead.
DbgPrint("OFS: Allocation error has occurred during IoAllocateErrorLogEntry call.\n");
goto Cleanup;
}
RtlZeroMemory(lpEntry, FIELD_OFFSET(IO_ERROR_LOG_PACKET, DumpData));
lpEntry->ErrorCode = ALFACW_DEBUG_INFORMATION;
lpEntry->NumberOfStrings = 1;
lpEntry->StringOffset = FIELD_OFFSET(IO_ERROR_LOG_PACKET, DumpData);
lpEntry->SequenceNumber = dwID;
// The string may contain at most (ERROR_LOG_MAXIMUM_SIZE -
// sizeof(IO_ERROR_LOG_PACKET)) / sizeof(WCHAR)
// characters. The "%2.2u: " part is exactly 4 characters (dwLen is at most 99, and is always
// padded with a zero if it's a single-digit number).
// One character is reserved for a NULL, and one is just an extra for testing. This is why
// the maximum length of the string, specified as an argument (%.*s) will be
// (ERROR_LOG_MAXIMUM_SIZE - sizeof(IO_ERROR_LOG_PACKET)) / sizeof(WCHAR) - 6.
ntRes = RtlStringCchPrintfW((PWCHAR)((PCHAR)lpEntry + lpEntry->StringOffset),
(ERROR_LOG_MAXIMUM_SIZE -
FIELD_OFFSET(IO_ERROR_LOG_PACKET, DumpData)) / sizeof(WCHAR),
L"%2.2u: %.*s",
dwID,
(ERROR_LOG_MAXIMUM_SIZE -
FIELD_OFFSET(IO_ERROR_LOG_PACKET, DumpData)) / sizeof(WCHAR) - 6,
lpLogBuffer);
if(!NT_SUCCESS(ntRes)) // SBO is not an acceptable error here.
{
DbgPrint("OFS: Error 0x%x has occurred during RtlStringCchVPrintfW call.\n", ntRes);
goto Cleanup;
}
ntRes = RtlStringCchLengthW((PWCHAR)((PCHAR)lpEntry + lpEntry->StringOffset),
(ERROR_LOG_MAXIMUM_SIZE -
FIELD_OFFSET(IO_ERROR_LOG_PACKET, DumpData)) / sizeof(WCHAR),
&dwLen);
if((dwLen * sizeof(WCHAR)) > (ERROR_LOG_MAXIMUM_SIZE - FIELD_OFFSET(IO_ERROR_LOG_PACKET, DumpData)))
{
DbgPrint("OFS: STATUS_BUFFER_OVERFLOW has occurred during RtlStringCchLengthW call.\n", ntRes);
goto Cleanup;
}
IoWriteErrorLogEntry(lpEntry);
lpEntry = NULL;
if(!NT_SUCCESS(ntRes) || (dwLen < 5))
{
DbgPrint("OFS: Error 0x%x has occurred during RtlStringCchLengthW call.\n", ntRes);
goto Cleanup;
}
// Each string has extra "00: " at the start, which is not part of the caller's buffer.
// NULL character is not counted for dwLen, because we are interested in how many characters
// of the lpLogBuffer got used exactly.
dwLen -= 4;
lpLogBuffer += dwLen; // dwLen is number of CHARS, do not *sizeof(WCHAR) here.
if(dwLen > dwFullLen)
{
dwFullLen = 0;
}
else
{
dwFullLen -= dwLen;
}
}
Cleanup:
if(lpBuffer)
{
OFS_FreeDirInfoBuffer(lpBuffer);
}
if(lpEntry)
{
IoFreeErrorLogEntry(lpEntry);
}
va_end(args);
}```
Cheers!