What does DebugView's "Enable Verbose Kernel Output" do?-CodePudding

I've followed Microsoft's "Write a Hello World Windows Driver (KMDF)" and wasn't sure how to see the output on WinDbg. After trying to set the Debug Print Filter registry to 0xFFFFFFFF, rebooting and other rain dance solutions, the one thing that worked was enabling DebugView's "Enable Verbose Kernel Output" option. Now, WinDbg shows debug outputs. Its too verbose but at least it's there.

So what did DebugView modify for WinDbg to show more verbose debug output?

I'm running WinDbg attached to a VM from my Windows host with a bridged connection.

CodePudding user response：

TL;DR: it calls a driver to repeatedly call NtSetDebugFilterState on all kernel components, so that they are all able to print something on the debug output.

Program

Let start with the program itself; there's only one occurrence of the sentence "Enable Verbose Kernel Output":

mov     [rsp 78h mi.wID], 9C7Ch
lea     rax, aEnableVerboseK ; "Enable &Verbose Kernel Output"
sbb     ecx, ecx
mov     [rsp 78h mi.dwTypeData], rax
and     ecx, 8
mov     [rsp 78h mi.fState], ecx
mov     rcx, cs:hMenu   ; hMenu
call    cs:GetSubMenu
mov     rcx, rax        ; hmenu
lea     r9, [rsp 78h mi] ; lpmi
lea     edx, [rdi 3]    ; item
lea     r8d, [rdi 1]    ; fByPosition
call    cs:InsertMenuItemA

The above code insert the sub-menu into the main menu. What's important here is the the menu ID, namely 0x9C7C.

This menu ID is used only once more here:

movzx   edx, al ; al can either be 0 or 1
xor     edi, edi
mov     qword ptr [rsp 830h iNumButtons], rdi ; lpOverlapped
lea     rax, [rsp 830h BytesReturned]
mov     [rsp 830h lpButtons], rax ; lpBytesReturned
xor     edx, 1
mov     dword ptr [rsp 830h wBMID], edi ; nOutBufferSize
xor     r9d, r9d        ; nInBufferSize
xor     r8d, r8d        ; lpInBuffer
mov     [rsp 830h dwInitParam], rdi ; lpOutBuffer
lea     edx, ds:0FFFFFFFF8305003Ch[rdx*4] ; dwIoControlCode
call    cs:DeviceIoControl
movzx   eax, cs:byte_1400935A3
mov     edx, 9C7Ch      ; uIDCheckItem
mov     rcx, cs:hMenu   ; hMenu
mov     cs:byte_1400A2776, al
neg     al
sbb     r8d, r8d
and     r8d, 8          ; uCheck
call    cs:CheckMenuItem

The above code calls DeviceIoControl and then checks the menu item. The former means the program is actually talking with a device driver.

If we remove a bit of code we can see which IOCTL can be sent to the driver:

movzx   edx, al ; al can either be 0 or 1
; snip
xor     edx, 1  ; invert AL
; snip
lea     edx, ds:0FFFFFFFF8305003Ch[rdx*4] ; dwIoControlCode
call    cs:DeviceIoControl

Since RDX can be either 0 or 1 we end up with (base 10):

[rdx*4-2096824260]

Thus:

4 - 2096824260 = -2096824256
0 - 2096824260 = -2096824260

Looking at the handles opened by dbgview64.exe we can see a \Device\dbgv is currently opened.

0: kd> !devobj \Device\dbgv
Device object (ffffd58a97007630) is for:
 Dbgv \Driver\DBGV DriverObject ffffd58a8688aaa0
Current Irp 00000000 RefCount 0 Type 00008305 Flags 00000048
SecurityDescriptor ffffe58fb8bdeea0 DevExt 00000000 DevObjExt ffffd58a97007780
ExtensionFlags (0x00000800)  DOE_DEFAULT_SD_PRESENT
Characteristics (0000000000)
Device queue is not busy.

0: kd> dt _driver_object ffffd58a8688aaa0
nt!_DRIVER_OBJECT
    0x000 Type             : 0n4
    0x002 Size             : 0n336
    0x008 DeviceObject     : 0xffffd58a`97007630 _DEVICE_OBJECT
    0x010 Flags            : 0x12
    0x018 DriverStart      : 0xfffff800`dcf90000 Void
    0x020 DriverSize       : 0x9000
    0x028 DriverSection    : 0xffffd58a`a3ba9be0 Void
    0x030 DriverExtension  : 0xffffd58a`8688abf0 _DRIVER_EXTENSION
    0x038 DriverName       : _UNICODE_STRING "\Driver\DBGV"
    0x048 HardwareDatabase : 0xfffff800`8372e990 _UNICODE_STRING "\REGISTRY\MACHINE\HARDWARE\DESCRIPTION\SYSTEM"
    0x050 FastIoDispatch   : (null)
    0x058 DriverInit       : 0xfffff800`dcf97058     long   0
    0x060 DriverStartIo    : (null)
    0x068 DriverUnload     : (null)
    0x070 MajorFunction    : [28] 0xfffff800`dcf91b80     long   0

0: kd> dt nt!_LDR_DATA_TABLE_ENTRY 0xffffd58a`a3ba9be0 Full*
    0x048 FullDllName : _UNICODE_STRING "\??\C:\WINDOWS\system32\Drivers\Dbgv.sys"

So the driver is currently loaded from C:\WINDOWS\system32\Drivers\Dbgv.sys (or you can extract it from the .rsrc section...).

Driver

Looking at the driver, in the driver entry we spot the function used for IRP_MJ_DEVICE_CONTROL:

lea     rax, sub_180001B80
mov     [rdi 0E0h], rax ; IRP_MJ_DEVICE_CONTROL
mov     [rdi 80h], rax
mov     [rdi 70h], rax

Inside that function we have the usual setup before calling the right IOCTL:

movzx   eax, [rcx _IO_STACK_LOCATION.MajorFunction]
mov     r9d, [rcx _IO_STACK_LOCATION.Parameters.DeviceIoControl.OutputBufferLength]
mov     r10d, [rcx _IO_STACK_LOCATION.Parameters.DeviceIoControl.IoControlCode]
test    al, al          ; IRP_MJ_CREATE
jz      loc_180001C6C
cmp     al, 2           ; IRP_MJ_CLOSE
jz      short loc_180001C0C
cmp     al, 0Eh         ; IRP_MJ_DEVICE_CONTROL
jnz     @@CompleteRequest
mov     eax, r10d
and     eax, 3
cmp     al, METHOD_NEITHER
jnz     short loc_180001BDF
mov     rdx, [rdi _IRP.UserBuffer]

loc_180001BDF:
mov     [rsp 98h do], r11 ; _DEVICE_OBJECT*
mov     [rsp 98h IoStatus], rbx ; IoStatus
mov     [rsp 98h ioctl], r10d ; IoCtl
mov     [rsp 98h OutputBufferLength], r9d ; OuputBufferLength
mov     r9d, [rcx _IO_STACK_LOCATION.Parameters.DeviceIoControl.InputBufferLength] ; int
mov     rcx, [rcx _IO_STACK_LOCATION.FileObject]
mov     qword ptr [rsp 98h Buffer], rdx ; Buffer
mov     dl, 1           ; int
call    sub_1800017E0
jmp     @@CompleteRequest

Inside the call (sub_1800017E0) we have a big switch for the IOCTL, here's the case -2096824260 (case -2096824256 is slightly different):

loc_1800018B9:
    call    sub_180002470   ; jumptable 000000018000182F case -2096824260
    jmp     loc_180001AEB

This function is mostly comprised of two loops:

loc_1800024A0:
                xor     ebx, ebx

@@LoopQuerySetDebugFilter:
                mov     edx, ebx
                mov     ecx, esi
                call    cs:qword_180005438 ; DbgQueryDebugFilterState
                mov     r8b, 1          ; State
                mov     edx, ebx        ; Level (keeps incrementing up to 0x1E)
                mov     ecx, esi        ; ComponentId (keeps incrementing up to 0x82)
                mov     [rdi], al       ; save current state.
                call    cs:qword_180005440 ; DbgSetDebugFilterState
                inc     ebx
                inc     rdi
                cmp     ebx, 1Eh
                jb      short @@LoopQuerySetDebugFilter
                inc     esi
                cmp     esi, 82h ; '‚'
                jb      short loc_1800024A0

Both calls are on DbgQueryDebugFilterState and DbgSetDebugFilterState (reactos source) which is just a minimal wrapper around NtSetDebugFilterState (reactos source).

As far as we can see the debug filter state is queried, saved, and then set for all kernel components (following is the component tables from the kernel, there are a lot of them):

.rdata:00000001400073E0 KdComponentTable dq offset Kd_SYSTEM_Mask
.rdata:00000001400073E0                                         ; DATA XREF: NtQueryDebugFilterState 36↓o
.rdata:00000001400073E0                                         ; NtSetDebugFilterState 43↓o ...
.rdata:00000001400073E8                 dq offset Kd_SMSS_Mask
.rdata:00000001400073F0                 dq offset Kd_SETUP_Mask
.rdata:00000001400073F8                 dq offset Kd_NTFS_Mask
.rdata:0000000140007400                 dq offset Kd_FSTUB_Mask
.rdata:0000000140007408                 dq offset Kd_CRASHDUMP_Mask
.rdata:0000000140007410                 dq offset Kd_CDAUDIO_Mask
.rdata:0000000140007418                 dq offset Kd_CDROM_Mask
.rdata:0000000140007420                 dq offset Kd_CLASSPNP_Mask
....

Which finally means that all kernel components are able to print something to the debug output.

Note that the other IOCTL just reset the components masks to what they were before checking the menu in the main program.