Skip to content

Debugging Tips

Jordan Rhee edited this page Mar 8, 2016 · 13 revisions

Viewing trace logs from the kernel mode driver (roskmd)

During development and debugging it is often useful to view log output from a software component. The kernel mode driver is instrumented with WPP logging and has the WPP in-flight recorder enabled. The in-flight recorder saves up to one page of the most recent tracing calls, which can be dumped from the debugger with the following command:

!rcdrkd.rcdrlogdump roskmd

You should see output similar to the following:

Trying to extract TMF information from - C:\debuggers\sym\roskmd.pdb\50607DB595DB494D985FEF3D0B1B6AA61\roskmd.pdb
--- start of log ---
1: RosKmdGlobal::DriverEntry -  [RosKmdGlobal.cpp @ 84] INFO :(pDriverObject=8AA97A10, pRegistryPath=8AACB000)
---- end of log ----

Note that the debugger must have access to the symbols to format the log output. Trace messages can also be sent to the kernel debugger in real time with the following command:

tracelog -start ros -rt -kd -guid #B5B486C1-F57B-4993-8ED7-E3C2F5E4E65A -flags 0xffff -level 5

To stop sending traces, run the following command

tracelog -stop ros

More information about WPP and ETW is available on MSDN.

The dxgkrnl logs can be dumped with the following command:

!dxgkdx.dxglog

Trace Macros

The following table describes the purpose of each trace macro and on which build flavors (debug/release) it is enabled.

Macro Name Description Enabled in Debug Builds Enabled in Release Builds
ROS_LOG_CRITICAL_ERROR Will cause bugcheck in release build. Yes Yes
ROS_LOG_ASSERTION Will cause debug break if debugger is attached. Yes No
ROS_LOG_ERROR Use to log all errors, e.g. before returning failure NTSTATUS. Yes Yes
ROS_LOG_LOW_MEMORY Use before returning STATUS_NO_MEMORY and STATUS_INSUFFICIENT_RESOURCES Yes Yes
ROS_LOG_WARNING Use to log things that are less severe than errors but more severe than information. Yes Yes
ROS_LOG_INFORMATION Use to log interesting events. Yes Yes
ROS_LOG_TRACE Use to log debugging information. Yes No
ROS_CRITICAL_ASSERT Will cause a bugcheck if the assertion expression evaluates to false. Yes Yes
ROS_ASSERT Will cause bugcheck if assertion expression evaluates to false. Yes No

Assorted Debugging Tips

Breaking in at driver entry

You can break in to the driver at the earliest possible point (DriverEntry) by using one of these techniques.

Hit Ctrl+Alt+K in windbg anytime before boot. This will break at kernel load. Run

sxe ld:roskmd.sys

This will cause the debugger to break in when the roskmd.sys module is loaded, but before any code is run. You can now load symbols and set a breakpoint on DriverEntry:

bp roskmd!DriverEntry

Assuming your symbol path is set up correctly, a breakpoint should be set.

You could also skip the 'sxe' step above by running the following command any time. This command does not require symbols to be loaded.

bu roskmd!DriverEntry

This sets a deferred breakpoint, which won't try to resolve the symbol to an address until the image is loaded.

Tell roskmd not to load

ed roskmd!RosKmdGlobal::s_bDoNotInstall 1

Skip loading of SiHost

reg add "HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows NT\CurrentVersion\Winlogon" /v ShellInfrastructure /t REG_SZ /d cmd.exe
reg add "HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows NT\CurrentVersion\Winlogon" /v Headless /t REG_DWORD  /d 1

Configure driver in render-only mode

reg add "HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\RenderOnlySample" /v RenderOnly /t REG_DWORD /d 1
reg add "HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\GraphicsDrivers" /v DisableAutoAcpiPostDeivce /t REG_DWORD /d 1
reg add HKLM\SOFTWARE\Microsoft\XAML /v ForceWARP /t REG_DWORD /d 1

Determining if DirectFlip is active

DirectFlip is a feature that allows full-screen applications to bypass the normal DWM composition process and flip application back buffers directly to the screen. During composition a rendering pass is performed that copies the entire frame buffer, so avoiding composition is necessary to achieve decent framerates. When DirectFlip is active, you should not see any calls to dxkgnl!DxgkPresent from the DWM, and roskmd!RosKmContext::Present should not get called. To determine if Present calls are coming from the app or from the DWM, set a breakpoint on dxkgnl!DxgkPresent,

bp dxgkrnl!DxgkPresent

When it gets hit, print out the current process:

!process -1 0

If the process is dwm.exe, DirectFlip is not being used. If the process is always the app, DirectFlip is being used.