diff --git a/.gitattributes b/.gitattributes new file mode 100644 index 0000000..1ff0c42 --- /dev/null +++ b/.gitattributes @@ -0,0 +1,63 @@ +############################################################################### +# Set default behavior to automatically normalize line endings. +############################################################################### +* text=auto + +############################################################################### +# Set default behavior for command prompt diff. +# +# This is need for earlier builds of msysgit that does not have it on by +# default for csharp files. +# Note: This is only used by command line +############################################################################### +#*.cs diff=csharp + +############################################################################### +# Set the merge driver for project and solution files +# +# Merging from the command prompt will add diff markers to the files if there +# are conflicts (Merging from VS is not affected by the settings below, in VS +# the diff markers are never inserted). Diff markers may cause the following +# file extensions to fail to load in VS. An alternative would be to treat +# these files as binary and thus will always conflict and require user +# intervention with every merge. To do so, just uncomment the entries below +############################################################################### +#*.sln merge=binary +#*.csproj merge=binary +#*.vbproj merge=binary +#*.vcxproj merge=binary +#*.vcproj merge=binary +#*.dbproj merge=binary +#*.fsproj merge=binary +#*.lsproj merge=binary +#*.wixproj merge=binary +#*.modelproj merge=binary +#*.sqlproj merge=binary +#*.wwaproj merge=binary + +############################################################################### +# behavior for image files +# +# image files are treated as binary by default. +############################################################################### +#*.jpg binary +#*.png binary +#*.gif binary + +############################################################################### +# diff behavior for common document formats +# +# Convert binary document formats to text before diffing them. This feature +# is only available from the command line. Turn it on by uncommenting the +# entries below. +############################################################################### +#*.doc diff=astextplain +#*.DOC diff=astextplain +#*.docx diff=astextplain +#*.DOCX diff=astextplain +#*.dot diff=astextplain +#*.DOT diff=astextplain +#*.pdf diff=astextplain +#*.PDF diff=astextplain +#*.rtf diff=astextplain +#*.RTF diff=astextplain diff --git a/.gitignore b/.gitignore index 259148f..e7dd979 100644 --- a/.gitignore +++ b/.gitignore @@ -1,32 +1,242 @@ -# Prerequisites -*.d - -# Compiled Object files -*.slo -*.lo -*.o -*.obj - -# Precompiled Headers -*.gch -*.pch - -# Compiled Dynamic libraries -*.so -*.dylib -*.dll - -# Fortran module files -*.mod -*.smod - -# Compiled Static libraries -*.lai -*.la -*.a -*.lib - -# Executables -*.exe -*.out -*.app +## Ignore Visual Studio temporary files, build results, and +## files generated by popular Visual Studio add-ons. + +# User-specific files +*.suo +*.user +*.userosscache +*.sln.docstates + +# User-specific files (MonoDevelop/Xamarin Studio) +*.userprefs + +# Build results +[Dd]ebug/ +[Dd]ebugPublic/ +[Rr]elease/ +[Rr]eleases/ +[Xx]64/ +[Xx]86/ +[Bb]uild/ +bld/ +[Bb]in/ +[Oo]bj/ + +# Visual Studio 2015 cache/options directory +.vs/ +# Uncomment if you have tasks that create the project's static files in wwwroot +#wwwroot/ + +# MSTest test Results +[Tt]est[Rr]esult*/ +[Bb]uild[Ll]og.* + +# NUNIT +*.VisualState.xml +TestResult.xml + +# Build Results of an ATL Project +[Dd]ebugPS/ +[Rr]eleasePS/ +dlldata.c + +# DNX +project.lock.json +artifacts/ + +*_i.c +*_p.c +*_i.h +*.ilk +*.meta +*.obj +*.pch +*.pdb +*.pgc +*.pgd +*.rsp +*.sbr +*.tlb +*.tli +*.tlh +*.tmp +*.tmp_proj +*.log +*.vspscc +*.vssscc +.builds +*.pidb +*.svclog +*.scc + +# Chutzpah Test files +_Chutzpah* + +# Visual C++ cache files +ipch/ +*.aps +*.ncb +*.opendb +*.opensdf +*.sdf +*.cachefile +*.VC.db + +# Visual Studio profiler +*.psess +*.vsp +*.vspx +*.sap + +# TFS 2012 Local Workspace +$tf/ + +# Guidance Automation Toolkit +*.gpState + +# ReSharper is a .NET coding add-in +_ReSharper*/ +*.[Rr]e[Ss]harper +*.DotSettings.user + +# JustCode is a .NET coding add-in +.JustCode + +# TeamCity is a build add-in +_TeamCity* + +# DotCover is a Code Coverage Tool +*.dotCover + +# NCrunch +_NCrunch_* +.*crunch*.local.xml +nCrunchTemp_* + +# MightyMoose +*.mm.* +AutoTest.Net/ + +# Web workbench (sass) +.sass-cache/ + +# Installshield output folder +[Ee]xpress/ + +# DocProject is a documentation generator add-in +DocProject/buildhelp/ +DocProject/Help/*.HxT +DocProject/Help/*.HxC +DocProject/Help/*.hhc +DocProject/Help/*.hhk +DocProject/Help/*.hhp +DocProject/Help/Html2 +DocProject/Help/html + +# Click-Once directory +publish/ + +# Publish Web Output +*.[Pp]ublish.xml +*.azurePubxml + +# TODO: Un-comment the next line if you do not want to checkin +# your web deploy settings because they may include unencrypted +# passwords +#*.pubxml +*.publishproj + +# NuGet Packages +*.nupkg +# The packages folder can be ignored because of Package Restore +**/packages/* +# except build/, which is used as an MSBuild target. +!**/packages/build/ +# Uncomment if necessary however generally it will be regenerated when needed +#!**/packages/repositories.config +# NuGet v3's project.json files produces more ignoreable files +*.nuget.props +*.nuget.targets + +# Microsoft Azure Build Output +csx/ +*.build.csdef + +# Microsoft Azure Emulator +ecf/ +rcf/ + +# Windows Store app package directory +AppPackages/ +BundleArtifacts/ + +# Visual Studio cache files +# files ending in .cache can be ignored +*.[Cc]ache +# but keep track of directories ending in .cache +!*.[Cc]ache/ + +# Others +ClientBin/ +[Ss]tyle[Cc]op.* +~$* +*~ +*.dbmdl +*.dbproj.schemaview +*.pfx +*.publishsettings +node_modules/ +orleans.codegen.cs + +# RIA/Silverlight projects +Generated_Code/ + +# Backup & report files from converting an old project file +# to a newer Visual Studio version. Backup files are not needed, +# because we have git ;-) +_UpgradeReport_Files/ +Backup*/ +UpgradeLog*.XML +UpgradeLog*.htm + +# SQL Server files +*.mdf +*.ldf + +# Business Intelligence projects +*.rdl.data +*.bim.layout +*.bim_*.settings + +# Microsoft Fakes +FakesAssemblies/ + +# GhostDoc plugin setting file +*.GhostDoc.xml + +# Node.js Tools for Visual Studio +.ntvs_analysis.dat + +# Visual Studio 6 build log +*.plg + +# Visual Studio 6 workspace options file +*.opt + +# Visual Studio LightSwitch build output +**/*.HTMLClient/GeneratedArtifacts +**/*.DesktopClient/GeneratedArtifacts +**/*.DesktopClient/ModelManifest.xml +**/*.Server/GeneratedArtifacts +**/*.Server/ModelManifest.xml +_Pvt_Extensions + +# LightSwitch generated files +GeneratedArtifacts/ +ModelManifest.xml + +# Paket dependency manager +.paket/paket.exe + +# FAKE - F# Make +.fake/ diff --git a/DebugLogger.sln b/DebugLogger.sln new file mode 100644 index 0000000..8d3bf5f --- /dev/null +++ b/DebugLogger.sln @@ -0,0 +1,68 @@ + +Microsoft Visual Studio Solution File, Format Version 12.00 +# Visual Studio 15 +VisualStudioVersion = 15.0.27906.1 +MinimumVisualStudioVersion = 10.0.40219.1 +Project("{8BC9CEB8-8B4A-11D0-8D11-00A0C91BC942}") = "DebugLogger", "DebugLogger\DebugLogger.vcxproj", "{A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}" +EndProject +Project("{8BC9CEB8-8B4A-11D0-8D11-00A0C91BC942}") = "TestDriver", "TestDriver\TestDriver.vcxproj", "{44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}" +EndProject +Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "Solution Items", "Solution Items", "{55E755F1-7E7F-4079-A163-689D2796C0F4}" + ProjectSection(SolutionItems) = preProject + README.md = README.md + EndProjectSection +EndProject +Global + GlobalSection(SolutionConfigurationPlatforms) = preSolution + Debug|ARM64 = Debug|ARM64 + Debug|x64 = Debug|x64 + Debug|x86 = Debug|x86 + Release|ARM64 = Release|ARM64 + Release|x64 = Release|x64 + Release|x86 = Release|x86 + EndGlobalSection + GlobalSection(ProjectConfigurationPlatforms) = postSolution + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Debug|ARM64.ActiveCfg = Debug|ARM64 + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Debug|ARM64.Build.0 = Debug|ARM64 + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Debug|ARM64.Deploy.0 = Debug|ARM64 + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Debug|x64.ActiveCfg = Debug|x64 + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Debug|x64.Build.0 = Debug|x64 + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Debug|x64.Deploy.0 = Debug|x64 + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Debug|x86.ActiveCfg = Debug|Win32 + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Debug|x86.Build.0 = Debug|Win32 + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Debug|x86.Deploy.0 = Debug|Win32 + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Release|ARM64.ActiveCfg = Release|ARM64 + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Release|ARM64.Build.0 = Release|ARM64 + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Release|ARM64.Deploy.0 = Release|ARM64 + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Release|x64.ActiveCfg = Release|x64 + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Release|x64.Build.0 = Release|x64 + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Release|x64.Deploy.0 = Release|x64 + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Release|x86.ActiveCfg = Release|Win32 + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Release|x86.Build.0 = Release|Win32 + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB}.Release|x86.Deploy.0 = Release|Win32 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Debug|ARM64.ActiveCfg = Debug|ARM64 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Debug|ARM64.Build.0 = Debug|ARM64 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Debug|ARM64.Deploy.0 = Debug|ARM64 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Debug|x64.ActiveCfg = Debug|x64 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Debug|x64.Build.0 = Debug|x64 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Debug|x64.Deploy.0 = Debug|x64 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Debug|x86.ActiveCfg = Debug|Win32 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Debug|x86.Build.0 = Debug|Win32 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Debug|x86.Deploy.0 = Debug|Win32 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Release|ARM64.ActiveCfg = Release|ARM64 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Release|ARM64.Build.0 = Release|ARM64 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Release|ARM64.Deploy.0 = Release|ARM64 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Release|x64.ActiveCfg = Release|x64 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Release|x64.Build.0 = Release|x64 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Release|x64.Deploy.0 = Release|x64 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Release|x86.ActiveCfg = Release|Win32 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Release|x86.Build.0 = Release|Win32 + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878}.Release|x86.Deploy.0 = Release|Win32 + EndGlobalSection + GlobalSection(SolutionProperties) = preSolution + HideSolutionNode = FALSE + EndGlobalSection + GlobalSection(ExtensibilityGlobals) = postSolution + SolutionGuid = {795694B7-88FD-4258-8B8E-377BD6BA6B9E} + EndGlobalSection +EndGlobal diff --git a/DebugLogger/DebugLogger.cpp b/DebugLogger/DebugLogger.cpp new file mode 100644 index 0000000..49e34b1 --- /dev/null +++ b/DebugLogger/DebugLogger.cpp @@ -0,0 +1,1071 @@ +/*! + @file DebugLogger.cpp + + @brief All C++ code of DebugLogger. + + @author Satoshi Tanda + + @copyright Copyright (c) 2018, Satoshi Tanda. All rights reserved. + */ +#include +#include + +// +// Define SYNCH_LEVEL for readability. SYNCH_LEVEL is 12 on both ARM64 and x64. +// +#ifndef SYNCH_LEVEL +#define SYNCH_LEVEL 12 +#endif + +// +// Handy macro to specify at which segment the code should be placed. +// +#define DEBUGLOGGER_INIT __declspec(code_seg("INIT")) +#define DEBUGLOGGER_PAGED __declspec(code_seg("PAGE")) + +// +// The size of log buffer in bytes. Two buffers of this size will be allocated. +// Change this as needed. +// +static const ULONG k_DebugLogBufferSize = PAGE_SIZE * 8; + +// +// The log file path. +// +DECLARE_CONST_UNICODE_STRING(k_LogFilePath, L"\\SystemRoot\\DebugLogger.log"); + +// +// The pool tag. +// +static const ULONG k_PoolTag = 'LgbD'; + +// +// The maximum characters the DbgPrint family can handle at once. +// +static const ULONG k_MaxDbgPrintLogLength = 512; + +// +// The format of how each debug log messages are store in buffer. The buffer is +// contains the sequence of this structure. +// +#include +typedef struct _DEBUG_LOG_ENTRY +{ + // + // The system time of when this message is seen in the debug print callback. + // + LARGE_INTEGER Timestamp; + + // + // The length of the message stored in LogLine in characters. + // + USHORT LogLineLength; + + // + // The debug log message, not including terminating null or '\n' or '\n'. + // + CHAR LogLine[ANYSIZE_ARRAY]; +} DEBUG_LOG_ENTRY, *PDEBUG_LOG_ENTRY; +static_assert(sizeof(DEBUG_LOG_ENTRY) == 11, "Must be packed for space"); +#include + +// +// Active and inactive buffer object. +// +typedef struct _DEBUG_LOG_BUFFER +{ + // + // The pointer to the buffer storing the sequence of DEBUG_LOG_ENTRYs. + // + PDEBUG_LOG_ENTRY LogEntries; + + // + // The offset to the address where the next DEBUG_LOG_ENTRY should be saved + // from LogEntries. + // + ULONG NextLogOffset; + + // + // How many bytes are not save into LogEntries due to lack of space. + // + ULONG OverflowedLogSize; +} DEBUG_LOG_BUFFER, *PDEBUG_LOG_BUFFER; + +// +// The structure used by the debug print callback. +// +typedef struct _PAIRED_DEBUG_LOG_BUFFER +{ + // + // Indicates whether ActiveLogBuffer and InactiveLogBuffer are usable. + // + BOOLEAN BufferValid; + + // + // The lock must be held before accessing any other fields of this structure. + // + EX_SPIN_LOCK ActiveLogBufferLock; + + // + // The pointers to two buffers: active and inactive. Active buffer is used + // by the debug print callback and actively save new messages as they show + // up. Inactive buffer is buffer being accessed and cleared up by the flush + // buffer thread. + // + PDEBUG_LOG_BUFFER ActiveLogBuffer; + PDEBUG_LOG_BUFFER InactiveLogBuffer; +} PAIRED_DEBUG_LOG_BUFFER, *PPAIRED_DEBUG_LOG_BUFFER; + +// +// The set of information the flush buffer thread may need. +// +typedef struct _FLUSH_BUFFER_THREAD_CONTEXT +{ + KEVENT ThreadExitEvent; + PPAIRED_DEBUG_LOG_BUFFER PairedLogBuffer; + HANDLE LogFileHandle; + PKTHREAD FlushBufferThread; + ULONG MaxOverflowedLogSize; +} FLUSH_BUFFER_THREAD_CONTEXT, *PFLUSH_BUFFER_THREAD_CONTEXT; + +// +// Buffer structures as global variables. Initialized by StartDebugPrintCallback +// and cleaned up by StopDebugPrintCallback. +// +static DEBUG_LOG_BUFFER g_LogBuffer1; +static DEBUG_LOG_BUFFER g_LogBuffer2; +static PAIRED_DEBUG_LOG_BUFFER g_PairedLogBuffer; + +// +// The thread context. Initialized by StartFlushBufferThread and cleaned up by +// StopFlushBufferThread. +// +static FLUSH_BUFFER_THREAD_CONTEXT g_ThreadContext; + +// +// The space to save old debug filter states for all components. Used by +// EnableVerboseDebugOutput and DisableVerboseDebugOutput. +// +static ULONG g_DebugFilterStates[DPFLTR_ENDOFTABLE_ID]; + +// +// Code analysis wants this declaration. +// +DEBUGLOGGER_INIT EXTERN_C DRIVER_INITIALIZE DriverEntry; + +/*! + @brief Saves a single line debug message to the active buffer. + + @param[in] Timestamp - The time stamp of when the log message was sent. + + @param[in] LogLine - The single line, null-terminated debug log message. + Does not include "\n". + + @param[in,out] PairedLogBuffer - Buffer to save the message. +*/ +static +_IRQL_requires_(SYNCH_LEVEL) +VOID +SaveDebugOutputLine ( + _In_ const LARGE_INTEGER* Timestamp, + _In_ PCCHAR LogLine, + _Inout_ PPAIRED_DEBUG_LOG_BUFFER PairedLogBuffer + ) +{ + USHORT logLineLength; + ULONG logEntrySize; + BOOLEAN lockAcquired; + PDEBUG_LOG_ENTRY logEntry; + + lockAcquired = FALSE; + + // + // Get the length of the message in characters. The message should never be + // an empty (as per behavior of strtok_s) and should never be longer than + // what the DbgPrint family can handle. + // + logLineLength = static_cast(strlen(LogLine)); + if ((logLineLength == 0) || (logLineLength > k_MaxDbgPrintLogLength)) + { + NT_ASSERT(FALSE); + goto Exit; + } + + // + // Unlikely but one can output \r\n. Ignore this to normalize contents. + // + if (LogLine[logLineLength - 1] == '\r') + { + if ((--logLineLength) == 0) + { + goto Exit; + } + } + + logEntrySize = RTL_SIZEOF_THROUGH_FIELD(DEBUG_LOG_ENTRY, LogLineLength) + + logLineLength; + + // + // Acquire the lock to safely modify active buffer. + // + ExAcquireSpinLockExclusiveAtDpcLevel(&PairedLogBuffer->ActiveLogBufferLock); + lockAcquired = TRUE; + + // + // Bail out if a concurrent thread invalidated buffer. + // + if (PairedLogBuffer->BufferValid == FALSE) + { + goto Exit; + } + + // + // If the remaining buffer is not large enough to save this message, count + // up the overflowed size and bail out. + // + if (PairedLogBuffer->ActiveLogBuffer->NextLogOffset + logEntrySize > k_DebugLogBufferSize) + { + PairedLogBuffer->ActiveLogBuffer->OverflowedLogSize += logEntrySize; + goto Exit; + } + + // + // There are sufficient room to save the message. Get the address to save + // the message within active buffer. On debug build, the address should be + // filled with 0xff, indicating no one has yet touched there. + // + logEntry = reinterpret_cast(Add2Ptr( + PairedLogBuffer->ActiveLogBuffer->LogEntries, + PairedLogBuffer->ActiveLogBuffer->NextLogOffset)); + NT_ASSERT(logEntry->Timestamp.QuadPart == MAXULONG64); + NT_ASSERT(logEntry->LogLineLength == MAXUSHORT); + + // + // Save this message and update the offset to the address to save the next + // message. + // + logEntry->Timestamp = *Timestamp; + logEntry->LogLineLength = logLineLength; + RtlCopyMemory(logEntry->LogLine, LogLine, logLineLength); + PairedLogBuffer->ActiveLogBuffer->NextLogOffset += logEntrySize; + +Exit: + if (lockAcquired != FALSE) + { + ExReleaseSpinLockExclusiveFromDpcLevel(&PairedLogBuffer->ActiveLogBufferLock); + } + return; +} + +/*! + @brief Saves the debug log messages to active buffer. + + @param[in] Output - The formatted debug log message given to the API family. + + @param[in,out] PairedLogBuffer - Buffer to save the message. +*/ +static +_IRQL_requires_(SYNCH_LEVEL) +VOID +SaveDebugOutput ( + _In_ const STRING* Output, + _Inout_ PPAIRED_DEBUG_LOG_BUFFER PairedLogBuffer + ) +{ + CHAR ouputBuffer[k_MaxDbgPrintLogLength + 1]; + PCHAR strtokContext; + PCHAR logLine; + LARGE_INTEGER timestamp; + + // + // Capture when the debug log message is sent. + // + KeQuerySystemTimePrecise(×tamp); + + // + // Ignore an empty message as it is not interesting. + // + if (Output->Length == 0) + { + goto Exit; + } + + // + // The message should be shorter than what the DbgPrint family can handle at + // one call. + // + if (Output->Length > k_MaxDbgPrintLogLength) + { + NT_ASSERT(FALSE); + goto Exit; + } + + // + // Copy the message as a null-terminated string. + // + RtlCopyMemory(ouputBuffer, Output->Buffer, Output->Length); + ouputBuffer[Output->Length] = ANSI_NULL; + + // + // Split it with \n and save each split message. Note that strtok_s removes + // "\n\n", so empty lines are not saved. + // + strtokContext = nullptr; + logLine = strtok_s(ouputBuffer, "\n", &strtokContext); + while (logLine != nullptr) + { + SaveDebugOutputLine(×tamp, logLine, PairedLogBuffer); + logLine = strtok_s(nullptr, "\n", &strtokContext); + } + +Exit: + return; +} + +/*! + @brief The callback routine for the DbgPrint family. + + @param[in] Output - The formatted debug log message given to the API family. + + @param[in] ComponentId - The ComponentId given to the API family. + + @param[in] Level - The Level given to the API family. +*/ +static +_IRQL_requires_max_(SYNCH_LEVEL) +VOID +DebugPrintCallback ( + _In_ PSTRING Output, + _In_ ULONG ComponentId, + _In_ ULONG Level + ) +{ + KIRQL oldIrql; + + UNREFERENCED_PARAMETER(ComponentId); + UNREFERENCED_PARAMETER(Level); + + // + // IRQL is expected to be SYNCH_LEVEL already, but raise it to make sure + // as an expected IRQL of this callback is not documented anywhere. + // + oldIrql = KeRaiseIrqlToSynchLevel(); + NT_ASSERT(oldIrql == SYNCH_LEVEL); + + // + // Do actual stuff with context. + // + SaveDebugOutput(Output, &g_PairedLogBuffer); + + KeLowerIrql(oldIrql); + return; +} + +/*! + @brief Disables verbose debug output by restoring filter states to original. +*/ +DEBUGLOGGER_PAGED +static +_IRQL_requires_max_(PASSIVE_LEVEL) +VOID +DisableVerboseDebugOutput ( + VOID + ) +{ + ULONG states; + BOOLEAN oldState; + + PAGED_CODE(); + + for (ULONG componentId = 0; componentId < DPFLTR_ENDOFTABLE_ID; ++componentId) + { + states = g_DebugFilterStates[componentId]; + for (ULONG level = 0; level < 32; ++level) + { + // + // Get the bit corresponding to the "level" from "states", and set + // that bit as a new state (restore). + // + oldState = BooleanFlagOn(states, (1 << level)); + NT_VERIFY(NT_SUCCESS(DbgSetDebugFilterState(componentId, level, oldState))); + } + } + +#if DBG + // + // Make sure that states of all components were reverted to the same states + // as stored in g_DebugFilterStates. + // + for (ULONG componentId = 0; componentId < DPFLTR_ENDOFTABLE_ID; ++componentId) + { + states = 0; + for (ULONG level = 0; level < 32; ++level) + { + oldState = static_cast(DbgQueryDebugFilterState(componentId, level)); + SetFlag(states, (oldState << level)); + } + NT_ASSERT(states == g_DebugFilterStates[componentId]); + } +#endif +} + +/*! + @brief Stops the debug print callback and cleans up paired buffer. + + @param[in,out] PairedLogBuffer - The paired buffer associated to clean up. +*/ +static +_IRQL_requires_max_(PASSIVE_LEVEL) +VOID +StopDebugPrintCallback ( + _Inout_ PPAIRED_DEBUG_LOG_BUFFER PairedLogBuffer + ) +{ + KIRQL oldIrql; + + // + // Restore debug filters to the previous states. + // + DisableVerboseDebugOutput(); + + // + // Stop the callback. + // + NT_VERIFY(NT_SUCCESS(DbgSetDebugPrintCallback(DebugPrintCallback, FALSE))); + + // + // Let us make sure no one is touching the paired buffer. Without this, it + // is possible that the callback is still running concurrently on the other + // processor and touching the paired buffer. + // + oldIrql = ExAcquireSpinLockExclusive(&PairedLogBuffer->ActiveLogBufferLock); + + // + // Free both buffer and mark this paired buffer as invalid, so the other + // thread waiting on this skin lock can tell the buffer is no longer valid + // when the spin lock was released. + // + ExFreePoolWithTag(PairedLogBuffer->ActiveLogBuffer->LogEntries, k_PoolTag); + ExFreePoolWithTag(PairedLogBuffer->InactiveLogBuffer->LogEntries, k_PoolTag); + PairedLogBuffer->BufferValid = FALSE; + + ExReleaseSpinLockExclusive(&PairedLogBuffer->ActiveLogBufferLock, oldIrql); +} + +/*! + @brief Stops the flush buffer thread and cleans up the thread context. + + @param[in,out] ThreadContext - The context associated to the thread and to + clean up. +*/ +DEBUGLOGGER_PAGED +static +_IRQL_requires_max_(PASSIVE_LEVEL) +VOID +StopFlushBufferThread ( + _Inout_ PFLUSH_BUFFER_THREAD_CONTEXT ThreadContext + ) +{ + NTSTATUS status; + + PAGED_CODE(); + + DbgPrintEx(DPFLTR_IHVDRIVER_ID, + DPFLTR_INFO_LEVEL, + "Stopping debug print logging.\n"); + + if (ThreadContext->MaxOverflowedLogSize != 0) + { + DbgPrintEx(DPFLTR_IHVDRIVER_ID, + DPFLTR_INFO_LEVEL, + "Max overflow size = 0x%x. Consider increasing the buffer" + " size and recompile the driver for the next run.\n", + ThreadContext->MaxOverflowedLogSize); + } + + // + // Signal the event to exit the thread, and wait for termination. + // + (VOID)KeSetEvent(&ThreadContext->ThreadExitEvent, IO_NO_INCREMENT, FALSE); + status = KeWaitForSingleObject(ThreadContext->FlushBufferThread, + Executive, + KernelMode, + FALSE, + nullptr); + NT_ASSERT(status == STATUS_SUCCESS); + ObDereferenceObject(ThreadContext->FlushBufferThread); + + // + // No one should be touching the log file now. Close it. + // + NT_VERIFY(NT_SUCCESS(ZwClose(ThreadContext->LogFileHandle))); +} + +/*! + @brief Stops debug print logging. +*/ +DEBUGLOGGER_PAGED +static +_IRQL_requires_max_(PASSIVE_LEVEL) +VOID +StopDebugPrintLoggging ( + VOID + ) +{ + PAGED_CODE(); + + StopFlushBufferThread(&g_ThreadContext); + StopDebugPrintCallback(&g_PairedLogBuffer); +} + +/*! + @brief Unloads this driver. + + @param[in] DriverObject - The associated driver object. +*/ +DEBUGLOGGER_PAGED +static +_Function_class_(DRIVER_UNLOAD) +_IRQL_requires_max_(PASSIVE_LEVEL) +VOID +DriverUnload ( + _In_ PDRIVER_OBJECT DriverObject + ) +{ + UNREFERENCED_PARAMETER(DriverObject); + + PAGED_CODE(); + + StopDebugPrintLoggging(); +} + +/*! + @brief Writes saved debug log messages into the log file and clears them. + + @details This function first swaps active buffer with inactive buffer, so + that the currently active buffer can safely be accessed (ie, inactive + buffer becomes active buffer). Then, writes contents of previously + active buffer into the log file if contents exist. Then, updates the max + overflow count as needed. Finally, it clears the contents of previously + active buffer to make it ready to become active buffer again. + + @param[in,out] ThreadContext - Context to be used by the thread. +*/ +static +_IRQL_requires_max_(PASSIVE_LEVEL) +VOID +FlushDebugLogEntries ( + _Inout_ PFLUSH_BUFFER_THREAD_CONTEXT ThreadContext + ) +{ + NTSTATUS status; + PPAIRED_DEBUG_LOG_BUFFER pairedLogBuffer; + KIRQL oldIrql; + PDEBUG_LOG_BUFFER oldLogBuffer; + IO_STATUS_BLOCK ioStatusBlock; + + status = STATUS_SUCCESS; + pairedLogBuffer = ThreadContext->PairedLogBuffer; + + // + // Swap active buffer and inactive buffer. + // + oldIrql = ExAcquireSpinLockExclusive(&pairedLogBuffer->ActiveLogBufferLock); + oldLogBuffer = pairedLogBuffer->ActiveLogBuffer; + pairedLogBuffer->ActiveLogBuffer = pairedLogBuffer->InactiveLogBuffer; + pairedLogBuffer->InactiveLogBuffer = oldLogBuffer; + ExReleaseSpinLockExclusive(&pairedLogBuffer->ActiveLogBufferLock, oldIrql); + + NT_ASSERT(pairedLogBuffer->ActiveLogBuffer != pairedLogBuffer->InactiveLogBuffer); + + // + // Iterate all saved debug log messages (if exist). + // + for (ULONG offset = 0; offset < oldLogBuffer->NextLogOffset; /**/) + { + PDEBUG_LOG_ENTRY logEntry; + CHAR writeBuffer[k_MaxDbgPrintLogLength + 50]; // 50 for date and time. + ANSI_STRING tmpLogLine; + TIME_FIELDS timeFields; + LARGE_INTEGER localTime; + + logEntry = reinterpret_cast(Add2Ptr( + oldLogBuffer->LogEntries, + offset)); + + // + // Build a temporal ANSI_STRING for stringify non-null terminated string. + // + tmpLogLine.Buffer = logEntry->LogLine; + tmpLogLine.Length = logEntry->LogLineLength; + tmpLogLine.MaximumLength = logEntry->LogLineLength; + + // + // Convert the time stamp to the local time in the human readable format. + // + ExSystemTimeToLocalTime(&logEntry->Timestamp, &localTime); + RtlTimeToTimeFields(&localTime, &timeFields); + + status = RtlStringCchPrintfA(writeBuffer, + RTL_NUMBER_OF(writeBuffer), + "%02hd-%02hd %02hd:%02hd:%02hd.%03hd %Z\r\n", + timeFields.Month, + timeFields.Day, + timeFields.Hour, + timeFields.Minute, + timeFields.Second, + timeFields.Milliseconds, + &tmpLogLine); + if (!NT_SUCCESS(status)) + { + // + // This should not happen, but if it does, just discard all log + // messages. The next attempt will very likely fail too. + // + NT_ASSERT(FALSE); + break; + } + + status = ZwWriteFile(ThreadContext->LogFileHandle, + nullptr, + nullptr, + nullptr, + &ioStatusBlock, + writeBuffer, + static_cast(strlen(writeBuffer)), + nullptr, + nullptr); + if (!NT_SUCCESS(status)) + { + // + // This can happen when the system is shutting down and the file + // system was already unmounted. Bail out, nothing we can do. + // + break; + } + + // + // Compute the offset to the next entry by adding the size of the current + // entry. + // + offset += RTL_SIZEOF_THROUGH_FIELD(DEBUG_LOG_ENTRY, LogLineLength) + + logEntry->LogLineLength; + } + + // + // If the debug log messages exist, and no error happened before, flush the + // log file. This should not fail (unless the file system is unmounted + // after the last successful write). + // + if ((oldLogBuffer->NextLogOffset != 0) && NT_SUCCESS(status)) + { + status = ZwFlushBuffersFile(ThreadContext->LogFileHandle, &ioStatusBlock); + NT_ASSERT(NT_SUCCESS(status)); + } + + // + // Update maximum overflow size as necessary. + // + ThreadContext->MaxOverflowedLogSize = max(ThreadContext->MaxOverflowedLogSize, + oldLogBuffer->OverflowedLogSize); + + // + // Finally, clear the previously active buffer. + // + oldLogBuffer->NextLogOffset = 0; + oldLogBuffer->OverflowedLogSize = 0; +#if DBG + RtlFillMemory(oldLogBuffer->LogEntries, k_DebugLogBufferSize, 0xff); +#endif +} + +/*! + @brief The entry point of the flush buffer thread. + + @param[in] Context - The thread context. +*/ +DEBUGLOGGER_PAGED +static +_Function_class_(KSTART_ROUTINE) +_IRQL_requires_max_(PASSIVE_LEVEL) +VOID +FlushBufferThreadEntryPoint ( + _In_ PVOID Context + ) +{ + static const ULONG intervalMs = 500; + NTSTATUS status; + PFLUSH_BUFFER_THREAD_CONTEXT threadContext; + LARGE_INTEGER interval; + + PAGED_CODE(); + + threadContext = reinterpret_cast(Context); + + interval.QuadPart = -(10000ll * intervalMs); + + do + { + // + // Flush log buffer with interval, or exit when it is requested. + // + status = KeWaitForSingleObject(&threadContext->ThreadExitEvent, + Executive, + KernelMode, + FALSE, + &interval); + FlushDebugLogEntries(threadContext); + } while (status == STATUS_TIMEOUT); + + // + // It is probably a programming error if non STATUS_SUCCESS is returned. Let + // us catch that. + // + NT_ASSERT(status == STATUS_SUCCESS); + PsTerminateSystemThread(status); +} + +/*! + @brief Enables all levels of debug print for all components. + + @details This function enables all debug print while saving the previous + state into g_DebugFilterStates for restore. +*/ +DEBUGLOGGER_INIT +static +VOID +EnableVerboseDebugOutput ( + VOID + ) +{ + ULONG statesOfAllLevels; + BOOLEAN state; + + PAGED_CODE(); + + // + // For all components. + // + for (ULONG componentId = 0; componentId < DPFLTR_ENDOFTABLE_ID; ++componentId) + { + // + // For all levels (levels are 0-31) of the component. + // + statesOfAllLevels = 0; + for (ULONG level = 0; level < 32; ++level) + { + // + // Get the current state, and save it as a single bit onto the 32bit + // integer (statesOfAllLevels). + // + state = static_cast(DbgQueryDebugFilterState(componentId, level)); + SetFlag(statesOfAllLevels, (state << level)); + + NT_VERIFY(NT_SUCCESS(DbgSetDebugFilterState(componentId, level, TRUE))); + } + g_DebugFilterStates[componentId] = statesOfAllLevels; + } +} + +/*! + @brief Starts the debug print callback. + + @details This function takes two buffers to be initialized, and one paired + buffer, which essentially references to those two buffers. All of them + are initialized in this function. + + @param[out] LogBufferActive - Debug log buffer to use initially. + + @param[out] LogBufferInactive - Debug log buffer to be inactive initially. + + @param[out] PairedLogBuffer - A buffer pair to be used in the debug print + callback. + + @return STATUS_SUCCESS or an appropriate status code. +*/ +DEBUGLOGGER_INIT +_IRQL_requires_max_(PASSIVE_LEVEL) +static +NTSTATUS +StartDebugPrintCallback ( + _Out_ PDEBUG_LOG_BUFFER LogBufferActive, + _Out_ PDEBUG_LOG_BUFFER LogBufferInactive, + _Out_ PPAIRED_DEBUG_LOG_BUFFER PairedLogBuffer + ) +{ + NTSTATUS status; + PDEBUG_LOG_ENTRY logEntries1, logEntries2; + + PAGED_CODE(); + + RtlZeroMemory(LogBufferActive, sizeof(*LogBufferActive)); + RtlZeroMemory(LogBufferInactive, sizeof(*LogBufferInactive)); + RtlZeroMemory(PairedLogBuffer, sizeof(*PairedLogBuffer)); + + logEntries2 = nullptr; + + // + // Allocate log buffers. + // + logEntries1 = reinterpret_cast(ExAllocatePoolWithTag( + NonPagedPoolNx, + k_DebugLogBufferSize, + k_PoolTag)); + if (logEntries1 == nullptr) + { + status = STATUS_INSUFFICIENT_RESOURCES; + goto Exit; + } + + logEntries2 = reinterpret_cast(ExAllocatePoolWithTag( + NonPagedPoolNx, + k_DebugLogBufferSize, + k_PoolTag)); + if (logEntries2 == nullptr) + { + status = STATUS_INSUFFICIENT_RESOURCES; + goto Exit; + } + +#if DBG + // + // Fill buffer contents with some distinguishable bytes for ease of debugging. + // + RtlFillMemory(logEntries1, k_DebugLogBufferSize, MAXUCHAR); + RtlFillMemory(logEntries2, k_DebugLogBufferSize, MAXUCHAR); +#endif + + // + // Initialize buffer variables, and mark the paired buffer as valid. This + // lets the debug print callback use this paired buffer. + // + LogBufferActive->LogEntries = logEntries1; + LogBufferInactive->LogEntries = logEntries2; + PairedLogBuffer->ActiveLogBuffer = LogBufferActive; + PairedLogBuffer->InactiveLogBuffer = LogBufferInactive; + PairedLogBuffer->BufferValid = TRUE; + + // + // We have set up everything the debug print callback needs. Start it. + // + status = DbgSetDebugPrintCallback(DebugPrintCallback, TRUE); + if (!NT_SUCCESS(status)) + { + goto Exit; + } + + // + // All good. Enable all levels of debug print for all components. + // + EnableVerboseDebugOutput(); + + DbgPrintEx(DPFLTR_IHVDRIVER_ID, + DPFLTR_INFO_LEVEL, + "Starting debug print logging.\n"); + +Exit: + if (!NT_SUCCESS(status)) + { + if (logEntries2 != nullptr) + { + ExFreePoolWithTag(logEntries2, k_PoolTag); + } + if (logEntries1 != nullptr) + { + ExFreePoolWithTag(logEntries1, k_PoolTag); + } + } + return status; +} + +/*! + @brief Starts the flush buffer thread. + + @param[out] ThreadContext - Context to be used by the thread. + + @return STATUS_SUCCESS or an appropriate status code. +*/ +DEBUGLOGGER_INIT +static +_IRQL_requires_max_(PASSIVE_LEVEL) +NTSTATUS +StartFlushBufferThread ( + _Out_ PFLUSH_BUFFER_THREAD_CONTEXT ThreadContext + ) +{ + static OBJECT_ATTRIBUTES attributes = RTL_CONSTANT_OBJECT_ATTRIBUTES( + &k_LogFilePath, + OBJ_KERNEL_HANDLE | OBJ_CASE_INSENSITIVE); + NTSTATUS status; + HANDLE fileHandle; + HANDLE threadHandle; + IO_STATUS_BLOCK ioStatusBlock; + PKTHREAD thread; + + PAGED_CODE(); + + RtlZeroMemory(ThreadContext, sizeof(*ThreadContext)); + fileHandle = nullptr; + + // + // Open or create the log file. Always append contents at the end. + // + status = ZwCreateFile(&fileHandle, + FILE_APPEND_DATA | SYNCHRONIZE, + &attributes, + &ioStatusBlock, + nullptr, + FILE_ATTRIBUTE_NORMAL, FILE_SHARE_READ, + FILE_OPEN_IF, + FILE_SYNCHRONOUS_IO_NONALERT | FILE_NON_DIRECTORY_FILE, + nullptr, + 0); + if (!NT_SUCCESS(status)) + { + goto Exit; + } + + // + // Initialize the context before creating the thread. This avoids race. + // + ThreadContext->LogFileHandle = fileHandle; + ThreadContext->PairedLogBuffer = &g_PairedLogBuffer; + KeInitializeEvent(&ThreadContext->ThreadExitEvent, SynchronizationEvent, FALSE); + + // + // Create the thread with the ready-to-use context. + // + status = PsCreateSystemThread(&threadHandle, + THREAD_ALL_ACCESS, + nullptr, + nullptr, + nullptr, + FlushBufferThreadEntryPoint, + ThreadContext); + if (!NT_SUCCESS(status)) + { + goto Exit; + } + + // + // Get the created thread object. This code does not fail (even the kernel + // code assumes so sometimes). + // + status = ObReferenceObjectByHandle(threadHandle, + THREAD_ALL_ACCESS, + *PsThreadType, + KernelMode, + reinterpret_cast(&thread), + nullptr); + NT_VERIFY(NT_SUCCESS(ZwClose(threadHandle))); + NT_ASSERT(NT_SUCCESS(status)); + + // + // FlushBufferThread is not referenced by the thread. So it is OK to + // initialize after creation of the thread. + // + ThreadContext->FlushBufferThread = thread; + +Exit: + if (!NT_SUCCESS(status)) + { + if (fileHandle != nullptr) + { + NT_VERIFY(NT_SUCCESS(ZwClose(fileHandle))); + } + } + return status; +} + +/*! + @brief Starts debug print logging. + + @return STATUS_SUCCESS or an appropriate status code. +*/ +DEBUGLOGGER_INIT +static +_IRQL_requires_max_(PASSIVE_LEVEL) +NTSTATUS +StartDebugPrintLogging ( + VOID + ) +{ + NTSTATUS status; + BOOLEAN callbackStarted; + + PAGED_CODE(); + + callbackStarted = FALSE; + + // + // Start debug print callback that saves debug print messages into one of + // those two buffers. + // + status = StartDebugPrintCallback(&g_LogBuffer1, &g_LogBuffer2, &g_PairedLogBuffer); + if (!NT_SUCCESS(status)) + { + goto Exit; + } + callbackStarted = TRUE; + + // + // Starts the flush buffer thread that write the saved debug print + // messages into a log file and clears the buffer. + // + status = StartFlushBufferThread(&g_ThreadContext); + if (!NT_SUCCESS(status)) + { + goto Exit; + } + +Exit: + if (!NT_SUCCESS(status)) + { + if (callbackStarted != FALSE) + { + StopDebugPrintCallback(&g_PairedLogBuffer); + } + } + return status; +} + +/*! + @brief The entry point of the driver. Starts debug print logging. + + @param[in] DriverObject - The associated driver object. + + @param[in] RegistryPath - The associated registry path. + + @return STATUS_SUCCESS or an appropriate status code. +*/ +DEBUGLOGGER_INIT +_Use_decl_annotations_ +NTSTATUS +DriverEntry ( + PDRIVER_OBJECT DriverObject, + PUNICODE_STRING RegistryPath + ) +{ + NTSTATUS status; + + UNREFERENCED_PARAMETER(RegistryPath); + + PAGED_CODE(); + + DriverObject->DriverUnload = DriverUnload; + + // + // Start debug print logging. This will fail when the driver started as Boot + // start because we try to open or create the log file while the file system + // is not mounted yet on that timing. Supporting that scenarios is pretty + // easy though. + // + status = StartDebugPrintLogging(); + if (!NT_SUCCESS(status)) + { + goto Exit; + } + +Exit: + return status; +} \ No newline at end of file diff --git a/DebugLogger/DebugLogger.inf b/DebugLogger/DebugLogger.inf new file mode 100644 index 0000000..5191059 --- /dev/null +++ b/DebugLogger/DebugLogger.inf @@ -0,0 +1,32 @@ +; +; DebugLogger.inf +; + +[Version] +Signature="$WINDOWS NT$" +Class=System +ClassGuid={4d36e97d-e325-11ce-bfc1-08002be10318} +Provider=%ManufacturerName% +DriverVer= +CatalogFile=DebugLogger.cat + +[DestinationDirs] +DefaultDestDir = 12 + + +[SourceDisksNames] +1 = %DiskName%,,,"" + +[SourceDisksFiles] + + +[Manufacturer] +%ManufacturerName%=Standard,NT$ARCH$ + +[Standard.NT$ARCH$] + + +[Strings] +ManufacturerName="" ;TODO: Replace with your manufacturer name +ClassName="" +DiskName="DebugLogger Source Disk" diff --git a/DebugLogger/DebugLogger.ruleset b/DebugLogger/DebugLogger.ruleset new file mode 100644 index 0000000..a3dcc5b --- /dev/null +++ b/DebugLogger/DebugLogger.ruleset @@ -0,0 +1,81 @@ + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + \ No newline at end of file diff --git a/DebugLogger/DebugLogger.vcxproj b/DebugLogger/DebugLogger.vcxproj new file mode 100644 index 0000000..5331375 --- /dev/null +++ b/DebugLogger/DebugLogger.vcxproj @@ -0,0 +1,167 @@ + + + + + Debug + Win32 + + + Release + Win32 + + + Debug + x64 + + + Release + x64 + + + Debug + ARM + + + Release + ARM + + + Debug + ARM64 + + + Release + ARM64 + + + + {A43C60C1-5FF6-410A-B59F-5C1C108CFEEB} + {dd38f7fc-d7bd-488b-9242-7d8754cde80d} + v4.5 + 12.0 + Debug + Win32 + DebugLogger + + + + true + WindowsKernelModeDriver10.0 + Driver + WDM + + + false + WindowsKernelModeDriver10.0 + Driver + WDM + + + true + WindowsKernelModeDriver10.0 + Driver + WDM + + + false + WindowsKernelModeDriver10.0 + Driver + WDM + + + true + WindowsKernelModeDriver10.0 + Driver + WDM + + + false + WindowsKernelModeDriver10.0 + Driver + WDM + + + true + WindowsKernelModeDriver10.0 + Driver + WDM + + + false + WindowsKernelModeDriver10.0 + Driver + WDM + + + + + + + + + + + DbgengKernelDebugger + DebugLogger.ruleset + + + DbgengKernelDebugger + DebugLogger.ruleset + + + DbgengKernelDebugger + DebugLogger.ruleset + + + DbgengKernelDebugger + DebugLogger.ruleset + + + DbgengKernelDebugger + DebugLogger.ruleset + + + DbgengKernelDebugger + DebugLogger.ruleset + + + DbgengKernelDebugger + DebugLogger.ruleset + + + DbgengKernelDebugger + DebugLogger.ruleset + + + + false + + + + + false + + + + + false + + + + + false + + + + + + + + + + + + + + + \ No newline at end of file diff --git a/DebugLogger/DebugLogger.vcxproj.filters b/DebugLogger/DebugLogger.vcxproj.filters new file mode 100644 index 0000000..edc077d --- /dev/null +++ b/DebugLogger/DebugLogger.vcxproj.filters @@ -0,0 +1,31 @@ + + + + + {4FC737F1-C7A5-4376-A066-2A32D752A2FF} + cpp;c;cc;cxx;def;odl;idl;hpj;bat;asm;asmx + + + {93995380-89BD-4b04-88EB-625FBE52EBFB} + h;hpp;hxx;hm;inl;inc;xsd + + + {67DA6AB6-F800-4c08-8B7A-83BB121AAD01} + rc;ico;cur;bmp;dlg;rc2;rct;bin;rgs;gif;jpg;jpeg;jpe;resx;tiff;tif;png;wav;mfcribbon-ms + + + {8E41214B-6785-4CFE-B992-037D68949A14} + inf;inv;inx;mof;mc; + + + + + Driver Files + + + + + Source Files + + + \ No newline at end of file diff --git a/Images/ExampleWithProcessHacker.jpg b/Images/ExampleWithProcessHacker.jpg new file mode 100644 index 0000000..cad9b27 Binary files /dev/null and b/Images/ExampleWithProcessHacker.jpg differ diff --git a/README.md b/README.md index 14a8a15..6336fa8 100644 --- a/README.md +++ b/README.md @@ -1 +1,117 @@ -# DebugLogger \ No newline at end of file +DebugLogger +============ + +Introduction +------------- + +DebugLogger is a software driver that lets you log kernel-mode debug output into +a file on Windows. DebugLogger can be understood as an open source implementation +of [Sysinternals DebugView](https://docs.microsoft.com/en-us/sysinternals/downloads/debugview) +with limited functionality. + + +Motivation +----------- + +Monitoring debug output is one of the most essential tasks for developing and +debugging device drivers on Windows. Developers can easily do this by either +attaching a kernel-debugger to the target system or using DebugView, which allows +developers to view debug output without attaching a kernel-debugger. + +Unfortunately, neither is an option when: + - your target system cannot run DebugView and does not have a necessary + interface to physically attach a kernel-debugger + - and, a virtual machine as a target system is unavailable + +The primary example of this situation is ARM64. I, for example, have an +[ASUS NovaGo TP370QL](https://www.asus.com/ca-en/2-in-1-PCs/ASUS-NovaGo-TP370QL/) +running Windows 10 on ARM64 processors, and it does not have an interface to +attach a kernel-debugger. Also, neither DebugView nor any virtualization solution +I am familiar with supports Windows on ARM64 processors. + +I was also under the exact same circumstance when I was developing a device driver +for Windows RT, which ran on ARM processors. I ended up with writing a file-based +logger to circumvent the issue, but it was not trivial and necessary work essentially. + +Having an open source implementation of DebugView-like tools allows developers to +participate in developing device drivers for such uncommon platforms more easily. + + +Comparison +----------- + +To clarify what DebugLogger can and cannot do, here is a brief comparison of +DebugLogger and DebugView. + +| | DebugLogger | DebugView | +|--------------------------------------------|-------------|--------------| +| kernel-mode debug output monitoring | YES | YES | +| Save debug output to a file | ALWAYS | YES | +| Enabling verbose kernel output | ALWAYS | YES | +| User-mode debug output monitoring | NO | YES | +| Boot time monitoring | NO | YES | +| Remote-system monitoring | NO | YES | +| Debug output inclusion / exclusion filters | NO | YES | +| Support of x86 Windows | NO | YES | +| Support of Windows 7 and older | NO | YES | +| Support of x64 Windows 10 | YES | NO BUT WORKS | +| Support of ARM64 Windows | YES | NO | +| Open source | YES | NO | + + +Usage +------ + +To the pre-compiled file **for ARM64**, goto +[Releases](https://github.com/tandasat/DebugLogger/releases) and download the +latest release. + +To build DebugLogger from source code, clone full source code from Github with +the below command and compile it on a supported version of Visual Studio. + + $ git clone https://github.com/tandasat/DebugLogger.git + +You have to enable test signing to install the driver before installing it. To +do that, open the command prompt with the administrator privilege and run the +following command, and then restart the system to activate the change: + + >bcdedit /set testsigning on + +To install and uninstall the DebugLogger driver, use the `sc` command. For +installation and start: + + >sc create DebugLogger type= kernel binPath= C:\Users\user\Desktop\DebugLogger.sys + >sc start DebugLogger + +For uninstallation: + + >sc stop DebugLogger + >sc delete DebugLogger + >bcdedit /deletevalue testsigning + + +Output +------- + +All captured debug output are saved in `C:\Windows\DebugLogger.log`. + +Any `tail -f` like command lets you view contents of this file real-time and +gives similar user experience as DebugView does. The below command does this: + + > powershell Get-Content -Path C:\Windows\DebugLogger.log -Wait + +Here is an example output from Process Hacker's KProcessHacker3 driver on the +ARM64 system. +![ExampleWithProcessHacker](/Images/ExampleWithProcessHacker.jpg) + +For the testing purpose, the test driver `TestDriver` is included in the project. +Install and run this driver using the `sc` command to see output. + + +Supported Platforms +-------------------- +- Visual Studio 2017 Preview (15.8 Preview 1 or later) + - You will need additional Visual Studio components to compile device drivers + for ARM64 processors. See [Building ARM64 Drivers with the WDK]( + https://docs.microsoft.com/en-us/windows-hardware/drivers/develop/building-arm64-drivers) for more information. +- 64bit versions of Windows 10 on ARM64 or x64 diff --git a/TestDriver/TestDriver.cpp b/TestDriver/TestDriver.cpp new file mode 100644 index 0000000..3bb135d --- /dev/null +++ b/TestDriver/TestDriver.cpp @@ -0,0 +1,54 @@ +/*! + @file TestDriver.cpp + + @brief The basic test driver against DebugLogger. + + @author Satoshi Tanda + + @copyright Copyright (c) 2018, Satoshi Tanda. All rights reserved. + */ +#include + +EXTERN_C DRIVER_INITIALIZE DriverEntry; + +NTSTATUS +DriverEntry ( + PDRIVER_OBJECT DriverObject, + PUNICODE_STRING RegistryPath + ) +{ + // + // Test log messages and expected output. + // + const PCHAR testLogLines[] = + { + "123", // -> "123" + "123\n", // -> "123" + "123\n ", // -> "123" + // -> " " + "123\r\n", // -> "123" + "12\n3", // -> "12" + // -> "3" + "12\n3\n", // -> "12" + // -> "3" + "12\n\n3", // -> "12" + // -> "3" + }; + + UNREFERENCED_PARAMETER(DriverObject); + UNREFERENCED_PARAMETER(RegistryPath); + + for (auto& line : testLogLines) + { + // + // It will be logged despite that the level is INFO and not ERROR + // because DebugLogger enters the system to the verbose mode. + // + DbgPrintEx(DPFLTR_IHVDRIVER_ID, DPFLTR_INFO_LEVEL, "%s", line); + } + + // + // Always fail so this driver gets unloaded automatically. + // + return STATUS_UNSUCCESSFUL; +} \ No newline at end of file diff --git a/TestDriver/TestDriver.inf b/TestDriver/TestDriver.inf new file mode 100644 index 0000000..89ed0ce --- /dev/null +++ b/TestDriver/TestDriver.inf @@ -0,0 +1,32 @@ +; +; TestDriver.inf +; + +[Version] +Signature="$WINDOWS NT$" +Class=System +ClassGuid={4d36e97d-e325-11ce-bfc1-08002be10318} +Provider=%ManufacturerName% +DriverVer= +CatalogFile=TestDriver.cat + +[DestinationDirs] +DefaultDestDir = 12 + + +[SourceDisksNames] +1 = %DiskName%,,,"" + +[SourceDisksFiles] + + +[Manufacturer] +%ManufacturerName%=Standard,NT$ARCH$ + +[Standard.NT$ARCH$] + + +[Strings] +ManufacturerName="" ;TODO: Replace with your manufacturer name +ClassName="" +DiskName="TestDriver Source Disk" diff --git a/TestDriver/TestDriver.vcxproj b/TestDriver/TestDriver.vcxproj new file mode 100644 index 0000000..4565297 --- /dev/null +++ b/TestDriver/TestDriver.vcxproj @@ -0,0 +1,167 @@ + + + + + Debug + Win32 + + + Release + Win32 + + + Debug + x64 + + + Release + x64 + + + Debug + ARM + + + Release + ARM + + + Debug + ARM64 + + + Release + ARM64 + + + + {44387148-C1CA-4D1C-BE1C-7AA2AE8D9878} + {dd38f7fc-d7bd-488b-9242-7d8754cde80d} + v4.5 + 12.0 + Debug + Win32 + TestDriver + + + + Windows10 + true + WindowsKernelModeDriver10.0 + Driver + WDM + + + Windows10 + false + WindowsKernelModeDriver10.0 + Driver + WDM + + + Windows10 + true + WindowsKernelModeDriver10.0 + Driver + WDM + + + Windows10 + false + WindowsKernelModeDriver10.0 + Driver + WDM + + + Windows10 + true + WindowsKernelModeDriver10.0 + Driver + WDM + + + Windows10 + false + WindowsKernelModeDriver10.0 + Driver + WDM + + + Windows10 + true + WindowsKernelModeDriver10.0 + Driver + WDM + + + Windows10 + false + WindowsKernelModeDriver10.0 + Driver + WDM + + + + + + + + + + + DbgengKernelDebugger + + + DbgengKernelDebugger + + + DbgengKernelDebugger + + + DbgengKernelDebugger + + + DbgengKernelDebugger + + + DbgengKernelDebugger + + + DbgengKernelDebugger + + + DbgengKernelDebugger + + + + false + + + + + false + + + + + false + + + + + false + + + + + + + + + + + + + + + \ No newline at end of file diff --git a/TestDriver/TestDriver.vcxproj.filters b/TestDriver/TestDriver.vcxproj.filters new file mode 100644 index 0000000..68ca527 --- /dev/null +++ b/TestDriver/TestDriver.vcxproj.filters @@ -0,0 +1,31 @@ + + + + + {4FC737F1-C7A5-4376-A066-2A32D752A2FF} + cpp;c;cc;cxx;def;odl;idl;hpj;bat;asm;asmx + + + {93995380-89BD-4b04-88EB-625FBE52EBFB} + h;hpp;hxx;hm;inl;inc;xsd + + + {67DA6AB6-F800-4c08-8B7A-83BB121AAD01} + rc;ico;cur;bmp;dlg;rc2;rct;bin;rgs;gif;jpg;jpeg;jpe;resx;tiff;tif;png;wav;mfcribbon-ms + + + {8E41214B-6785-4CFE-B992-037D68949A14} + inf;inv;inx;mof;mc; + + + + + Driver Files + + + + + Source Files + + + \ No newline at end of file