A Debugging Approach to OutputDebugString
Using OutputDebugString is a common debugging technique for user mode debugging. It is easy but quite useful if you are debugging services or trouble shooting loader problem.
#define WIN32_LEAN_AND_MEAN
#include <Windows.h>
int __cdecl main()
{
OutputDebugStringA("Hello, world! (first chance)\n");
OutputDebugStringW(L"Hello, world! (second chance)\n");
}
When you debug this demo application using Visual Studio, you would see the text messages from the Output window:
And if you are running this demo without debugging it, you can actually use DbgView to see the outputs (the Microsoft Platform SDK also comes with a console application called Dbmon.Exe):
Have you ever wondered how it works?
Let's launch the demo application from WinDBG (I'm using 32bit Win7, you might see different things if you are using other version of Windows):
windbg.exe outputdebugstring.exe
0:000> x kernel*!OutputDebugString*
760c1321 KERNELBASE!OutputDebugStringA
760c1585 KERNELBASE!OutputDebugStringW
766e6df2 kernel32!OutputDebugStringW
766ef0f0 kernel32!OutputDebugStringA
0:000> bp kernelbase!OutputDebugStringW
0:000> bl
0 e 760c1585 0001 (0001) 0:**** KERNELBASE!OutputDebugStringW
0:000> g
Hello, world! (first chance)
Breakpoint 0 hit
KERNELBASE!OutputDebugStringW:
760c1585 8bff mov edi,edi
0:000> pc
KERNELBASE!OutputDebugStringW+0x1d:
760c15a2 ff15ec110a76 call dword ptr [KERNELBASE+0x11ec (760a11ec)]
ds:0023:760a11ec={ntdll!RtlInitUnicodeStringEx (77d86f0a)}
0:000> pc
KERNELBASE!OutputDebugStringW+0x33:
760c15b8 ff1500100a76 call dword ptr [KERNELBASE+0x1000 (760a1000)]
ds:0023:760a1000={ntdll!RtlUnicodeStringToAnsiString (77d89e8e)}
0:000> pc
KERNELBASE!OutputDebugStringW+0x42:
760c15c7 e855fdffff call KERNELBASE!OutputDebugStringA (760c1321)
If we continue tracing, eventually we will reach this point:
ChildEBP RetAddr
0015f610 77d762a4 ntdll!KiFastSystemCall
0015f614 77d770fd ntdll!ZwRaiseException+0xc
0015f8f8 760ad36f ntdll!RtlRaiseException+0x35
0015f954 760c1375 KERNELBASE!RaiseException+0x58
0015fbc0 01351021 KERNELBASE!OutputDebugStringA+0x286
Dump the SEH chain:
0:000> dt nt!_EXCEPTION_REGISTRATION_RECORD -r poi(fs:[0])
ntdll!_EXCEPTION_REGISTRATION_RECORD
+0x000 Next : 0x0016fd58 _EXCEPTION_REGISTRATION_RECORD
+0x000 Next : 0x0016fdac _EXCEPTION_REGISTRATION_RECORD
+0x000 Next : 0xffffffff _EXCEPTION_REGISTRATION_RECORD
+0x004 Handler : 0x77d4e0ed _EXCEPTION_DISPOSITION ntdll!_except_handler4+0
+0x004 Handler : 0x00a72440 _EXCEPTION_DISPOSITION outputdebugstring!_except_handler4+0
+0x004 Handler : 0x760c1425 _EXCEPTION_DISPOSITION KERNELBASE!_except_handler4+0
0:000> !exchain
0029fcb0: KERNELBASE!_except_handler4+0 (760c1425)
CRT scope 0, filter: KERNELBASE!OutputDebugStringA+60 (760c13bc)
func: KERNELBASE!OutputDebugStringA+74 (760c11d1)
0029fd10: outputdebugstring!_except_handler4+0 (00e72440)
CRT scope 0, filter: outputdebugstring!__tmainCRTStartup+1f4 (00e71584)
func: outputdebugstring!__tmainCRTStartup+20f (00e7159f)
0029fd64: ntdll!_except_handler4+0 (77d4e0ed)
CRT scope 0, filter: ntdll!__RtlUserThreadStart+2e (77da7eeb)
func: ntdll!__RtlUserThreadStart+63 (77da8260)
An SEH was chained, and the control is returned to the OS kernel.
0:000> u 760c11d1 L20
KERNELBASE!OutputDebugStringA+0x74:
760c11d1 8b65e8 mov esp,dword ptr [ebp-18h]
760c11d4 33ff xor edi,edi
760c11d6 89bdd0fdffff mov dword ptr [ebp-230h],edi
760c11dc 89bddcfdffff mov dword ptr [ebp-224h],edi
760c11e2 89bdd4fdffff mov dword ptr [ebp-22Ch],edi
760c11e8 89bde0fdffff mov dword ptr [ebp-220h],edi
760c11ee e86d56feff call KERNELBASE!GetLastError (760a6860)
760c11f3 8985c8fdffff mov dword ptr [ebp-238h],eax
760c11f9 393d28490e76 cmp dword ptr [KERNELBASE!BaseDataFileHandleTableLock+0x4 (760e4928)],edi
760c11ff 0f8457040000 je KERNELBASE!OutputDebugStringA+0xa4 (760c165c)
760c1205 a128490e76 mov eax,dword ptr [KERNELBASE!BaseDataFileHandleTableLock+0x4 (760e4928)]
760c120a 3bc7 cmp eax,edi
760c120c 7441 je KERNELBASE!OutputDebugStringA+0x166 (760c124f)
760c120e 6810270000 push 2710h
760c1213 50 push eax
760c1214 e83666feff call KERNELBASE!WaitForSingleObject (760a784f)
760c1219 3bc7 cmp eax,edi
760c121b 0f8570040000 jne KERNELBASE!OutputDebugStringA+0xf3 (760c1691)
760c1221 6870120c76 push offset KERNELBASE!`string' (760c1270)
760c1226 57 push edi
760c1227 6a02 push 2
760c1229 e8df7bfeff call KERNELBASE!OpenFileMappingW (760a8e0d)
760c122e 8985d0fdffff mov dword ptr [ebp-230h],eax
760c1234 3bc7 cmp eax,edi
760c1236 0f85dea00000 jne KERNELBASE!OutputDebugStringA+0x111 (760cb31a)
760c123c 39bde0fdffff cmp dword ptr [ebp-220h],edi
760c1242 750b jne KERNELBASE!OutputDebugStringA+0x166 (760c124f)
760c1244 ff3528490e76 push dword ptr [KERNELBASE!BaseDataFileHandleTableLock+0x4 (760e4928)]
760c124a e81204feff call KERNELBASE!ReleaseMutex (760a1661)
760c124f c745fc01000000 mov dword ptr [ebp-4],1
760c1256 c745fc02000000 mov dword ptr [ebp-4],2
760c125d 8b85ccfdffff mov eax,dword ptr [ebp-234h]
As we could see from the disassembly, the byte value on 0x760c11d1 is 0x8b, let's change it to INT3:
0:000> ?? *(char*)(0x760c11d1) = 0xcc
char 0n-52 ''
Before we can continue, let's make sure WinDBG is installed as the Just-In-Time debugger by running the following command from an Elevated Command Prompt:
windbg.exe -IS
Now we are ready to continue:
0:000> .detach
Detached
NoTarget> q
On the same time, Just-In-Time debugging is triggered and another WinDBG just pops up with the following information:
(aa0.11cc): Break instruction exception - code 80000003 (!!! second chance !!!)
KERNELBASE!OutputDebugStringA+0x74:
760c11d1 cc int 3
Change the value on 0x760c11d1 back (or did you just forget the value?).
0:000> ?? *(char*)(0x760c11d1) = 0x8b
char 0n-117 ''
Euphoria:
KERNELBASE!DbgPrint:
760c11cb ff251c130a76 jmp dword ptr [KERNELBASE!_imp__DbgPrint (760a131c)]
760c11d1 8b65e8 mov esp,dword ptr [ebp-18h] ss:0023:0022fbb8=0022f97c
760c11d4 33ff xor edi,edi
760c11d6 89bdd0fdffff mov dword ptr [ebp-230h],edi
I'll leave the rest things for you to figure out. Hints:
You may want to use dda esp to dump the stack.
0:000> dda esp
0022f97c 4464c9b1
0022f980 00000000
0022f984 0022fbdc ""
0022f988 7ffd4000 ""
0022f98c 0000001e
0022f990 008f573c "Hello, world! (first chance). "
0022f994 002c00c4 ".,,"
0022f998 00000000You would eventually see something like CreateDBWinMutex.
When you encountered with OpenEvent or similar function call, you can use da to check the string parameter.
0:000> da 760cb478
760cb478 "DBWIN_BUFFER_READY"
Now we have finished the debugging approach to OutputDebugString, it's time to start writing a simple user mode dbgview:
#define WIN32_LEAN_AND_MEAN
#include <Windows.h>
#include <stdio.h>
#define IfFalseRet(c) do{if(!(c)){return dwLastError = ::GetLastError();}}while(false)
class CHandle
{
public:
CHandle(HANDLE h = NULL): m_h(h)
{
}
~CHandle()
{
Release();
}
void Release()
{
if(*this)
{
::CloseHandle(m_h);
}
m_h = NULL;
}
operator bool() const
{
return m_h != INVALID_HANDLE_VALUE && m_h != NULL;
}
operator HANDLE() const
{
return m_h;
}
CHandle& operator= (const HANDLE& h)
{
Release();
m_h = h;
return *this;
}
CHandle& operator= (CHandle& h)
{
if(this != &h)
{
HANDLE hSwap = m_h;
m_h = h.m_h;
h.m_h = hSwap;
h.Release();
}
return *this;
}
private:
HANDLE m_h;
};
LPCTSTR DBWIN_BUFFER = TEXT("DBWIN_BUFFER");
LPCTSTR DBWIN_BUFFER_READY = TEXT("DBWIN_BUFFER_READY");
LPCTSTR DBWIN_DATA_READY = TEXT("DBWIN_DATA_READY");
LPCTSTR DBWIN_MUTEX = TEXT("DBWinMutex");
#pragma pack(push, 1)
struct CDBWinBuffer
{
DWORD dwProcessId;
BYTE abData[4096 - sizeof(DWORD)];
};
#pragma pack(pop)
bool g_fContinue = true;
BOOL CtrlHandler(DWORD fdwCtrlType)
{
switch(fdwCtrlType)
{
case CTRL_C_EVENT:
case CTRL_CLOSE_EVENT:
case CTRL_LOGOFF_EVENT:
case CTRL_SHUTDOWN_EVENT:
g_fContinue = false;
return TRUE;
}
return FALSE;
}
int __cdecl main()
{
DWORD dwLastError = ERROR_SUCCESS;
IfFalseRet(SetConsoleCtrlHandler((PHANDLER_ROUTINE)(CtrlHandler), TRUE) == TRUE);
CHandle hMutex = OpenMutex(MUTEX_ALL_ACCESS, FALSE, DBWIN_MUTEX);
if(!hMutex)
{
IfFalseRet(GetLastError() == ERROR_FILE_NOT_FOUND);
IfFalseRet(hMutex = CreateMutex(NULL, FALSE, DBWIN_MUTEX));
}
CHandle hEventBufferReady = OpenEvent(EVENT_MODIFY_STATE, FALSE, DBWIN_BUFFER_READY);
if(!hEventBufferReady)
{
IfFalseRet(GetLastError() == ERROR_FILE_NOT_FOUND);
IfFalseRet(hEventBufferReady = CreateEvent(NULL, FALSE, TRUE, DBWIN_BUFFER_READY));
}
CHandle hEventDataReady = OpenEvent(EVENT_MODIFY_STATE, FALSE, DBWIN_DATA_READY);
if(!hEventDataReady)
{
IfFalseRet(GetLastError() == ERROR_FILE_NOT_FOUND);
IfFalseRet(hEventDataReady = CreateEvent(NULL, FALSE, FALSE, DBWIN_DATA_READY));
}
CHandle hFileMappingBuffer = OpenFileMapping(FILE_MAP_READ, FALSE, DBWIN_BUFFER);
if(!hFileMappingBuffer)
{
IfFalseRet(GetLastError() == ERROR_FILE_NOT_FOUND);
IfFalseRet(hFileMappingBuffer = CreateFileMapping(
INVALID_HANDLE_VALUE, NULL, PAGE_READWRITE,
0, sizeof(CDBWinBuffer), DBWIN_BUFFER));
}
CDBWinBuffer* pDbgBuffer = (CDBWinBuffer*)(MapViewOfFile(
hFileMappingBuffer, SECTION_MAP_READ, 0, 0, 0));
IfFalseRet(pDbgBuffer);
while(g_fContinue)
{
if(WaitForSingleObject(hEventDataReady, 100) == WAIT_OBJECT_0)
{
printf("%s", pDbgBuffer->abData);
SetEvent(hEventBufferReady);
}
}
UnmapViewOfFile(pDbgBuffer);
return dwLastError;
}
Notes:
- You will need to run the sample from an Elevated Command Prompt.
- The debug buffer guarantees you that the string is NUL terminated (any string longer than 4091 will be truncated).
- To make the sample easier, I just pass pDbgBuffer->abData to printf without performing any decoding (I just treated them as ASCII string).
- DbgPrint is defined for each execution environment, for user mode this would be ntdll!DbgPrint. ntdll!DbgPrint would call into KdpTrap which would in turn output the bytes to the Debug Port. You may find it more convenient to use DbgPrint instead of OutputDebugString as DbgPrint supports string formatting, but be cautious with the potential breaking changes in NTDLL.
Homework:
- As you might have discovered already, the underneath mechanism of OutputDebugString makes use of shared objects. What would happen if we forget to set the DBWIN_BUFFER_READY event?
- On 64bit Windows, the 32bit application runs under WoW64. Does the WoW64 own a separate set of OutputDebugString objects, or share with the 64bit environment?
- How would OutputDebugStringA|W be implemented using a same shared buffer?
For the homework, you may find some hints from the WinDBG output, where I've already marked in color.