In my previous post I spoke about finding a problem with
the Intel UHCI USB driver. In this post I will explain how we found the cause
of problem and what tools we used.
Already a long time ago I wrote a little tool called
‘SetDbgZone.exe’. What is it and why did I wrote it? Well, sometimes your
Windows CE image drivers suffer from intermittent problems that you didn’t
encounter when you were developing and testing the driver. Even worse, a bug
shows up in a RELEASE build and not in a DEBUG build. The latter reason is why
I initially wrote ‘SetDbgZone.exe’. I based myself at that time on several of Sue
Loh’s blogs.
In a DEBUG build, you can quite easily turn on ‘CE Debug
Zones’ in Platform Builder. This will give you extra runtime logging (showing
up in Output Window of Platform Builder) that can help you track down problems.
These DEBUG messages are typically generated in your code by the DEBUGMSG macro
in combination with ‘DBGPARAM dpCurSettings’ structure and DEBUGMASK macro. In
a RELEASE build however, these macros are typically compiled out of your code.
But I found out that you can keep this logging mechanism available in a RELEASE
build as well. Let’s see how
First of all you need to change the DEBUGMSG to your own
macro in your driver (and by extension you can adapt all the Microsoft sample
drivers in the same way). I called it _LOGMSG
As you can see, the _LOGMSG macro reverts to DEBUGMSG in
a DEBUG build, nothing new. However in a RELEASE build I redirect it to the RETAILCELOGMSG
macro (see also #include <dbgapi.h>).
This macro will send your runtime logging to CELOG. Now this is interesting as
CELOG can also work in RELEASE. CELOG for instance is also used by
KernelTracker to track kernel events. But you can add your own messages to
CELOG. There is a lot to learn about CELOG,
but for now you should know that CELOG is a circular log memory buffer in RAM
and that you use ‘CeLogFlush.exe’ to dump the RAM contents to disk. You can
also use ‘OsCapture.exe’, but I use ‘CeLogFlush.exe’ most of the time.
You can control CELOG via the Build Options of your
project, but I prefer not to do it that way. Instead I add the required
components myself in my image via OsDesign.bib
So far we have only made sure that our _LOGMSG macro logs
to the CELOG buffer. But only if the DEBUGMASK bit is set in the dpCurSettings
structure. By default - certainly in a RELEASE build - all DEBUGMASK bits are
set to false (off). Note that the price we pay for _LOGMSG in RELEASE is an
extra ‘small’ if-statement to see if any logging needs to be sent to CELOG. If
the DEBUGMASK bit is off, nothing more will happen. This is the only runtime
performance hit you will have, most of the time negligible according to my
experience.
Now, how do you switch the DEBUGMASK bit to true (on)?
That is where ‘SetDbgZone.exe’ comes into play. These days this API is well
documented in MSDN, in the CE 4 era I looked at the shared source code of this
API to see how it worked. ‘SetDbgZone.exe’ is a small command line tool that I
also include with my image. At the end of the blog, you can find the source
code. It basically uses the ToolHelp API to find the process (exe) or module
(dll) of interest and calls SetDbgZone() API on it. This API will set the
corresponding DEBUGMASK bits in the dpCurSettings structure, if it exists in
the process or module. Note that the structure always has to have this name. If
you work a lot with Windows CE, one of the first words you should learn is
’dpCurSettings’! It’s the same structure you need to search for in source code
to know what registry name you have to set in the Pegasus registry key to have
‘Ce Debug Zones’ turned on from boot when debugging with Platform Builder, but
that is another (well known?) story…
With this scenario I can still debug and collect CeLog traces of my image, even when the image is already out-in-the-field. Also know that an end user application can also write to CeLog, this allows you to combine image and user application information, which might be crucial to track down some problems...
#include <windows.h>
#include <windows.h>
#include <windows.h>
#include <toolhelp.h>
#include <tlhelp32.h>
#include <string>
#include <map>
#include <stdlib.h>
std::map<std::wstring,
DWORD> g_processes;
std::map<std::wstring,
DWORD> g_modules;
void EnumerateProcessesAndModules()
{
HANDLE snapShotProcess =
INVALID_HANDLE_VALUE;
snapShotProcess =
CreateToolhelp32Snapshot(TH32CS_SNAPPROCESS | TH32CS_SNAPNOHEAPS, 0);
if (snapShotProcess !=
INVALID_HANDLE_VALUE)
{
// Build
new list
int c = 0;
PROCESSENTRY32 processEntry;
processEntry.dwSize = sizeof(PROCESSENTRY32);
BOOL retProcess =
Process32First(snapShotProcess, &processEntry);
while (retProcess == TRUE)
{
wchar_t fullProcessName[256];
wsprintf(fullProcessName, L"%08X-%s",
processEntry.th32ProcessID, processEntry.szExeFile);
g_processes[fullProcessName] =
processEntry.th32ProcessID;
HANDLE snapShotModule =
INVALID_HANDLE_VALUE;
snapShotModule =
CreateToolhelp32Snapshot(TH32CS_SNAPMODULE, processEntry.th32ProcessID);
if (snapShotModule != INVALID_HANDLE_VALUE)
{
MODULEENTRY32 moduleEntry;
moduleEntry.dwSize = sizeof(MODULEENTRY32);
BOOL retModule =
Module32First(snapShotModule, &moduleEntry);
while (retModule == TRUE)
{
g_modules[moduleEntry.szModule] = moduleEntry.th32ModuleID;
retModule =
Module32Next(snapShotModule, &moduleEntry);
}
CloseToolhelp32Snapshot(snapShotModule);
}
retProcess =
Process32Next(snapShotProcess, &processEntry);
}
CloseToolhelp32Snapshot(snapShotProcess);
}
}
void ListProcesses()
{
wprintf(L"Current
process list\r\n");
size_t size = g_processes.size();
int c = 0;
std::map<std::wstring,
DWORD>::const_iterator iter;
for (iter = g_processes.begin(); iter != g_processes.end();
++iter)
{
wprintf(L"
%03d [%08X] : %s\r\n", ++c, iter->second,
iter->first.c_str());
}
}
void ListModules()
{
wprintf(L"Current
module list\r\n");
size_t size = g_modules.size();
int c = 0;
std::map<std::wstring,
DWORD>::const_iterator iter;
for (iter = g_modules.begin(); iter != g_modules.end(); ++iter)
{
wprintf(L"
%03d [%08X] : %s\r\n", ++c, iter->second,
iter->first.c_str());
}
}
DWORD
GetProcessId(const wchar_t* process)
{
if (process == NULL) return 0;
std::map<std::wstring,
DWORD>::const_iterator iter = g_processes.begin();
while ((iter != g_processes.end()) && (wcsicmp(process,
iter->first.c_str()) != 0))
{
++iter;
}
if (iter != g_processes.end()) return iter->second;
return 0;
}
DWORD
GetModuleId(const wchar_t* module)
{
if (module == NULL) return 0;
std::map<std::wstring,
DWORD>::const_iterator iter = g_modules.begin();
while ((iter != g_modules.end()) && (wcsicmp(module,
iter->first.c_str()) != 0))
{
++iter;
}
if (iter != g_modules.end()) return iter->second;
return 0;
}
void PrintHelp()
{
wprintf(L"
DbgZone.exe [/p|/m] [/?]\r\n");
wprintf(L" /p
: list all processes\r\n");
wprintf(L" /p=xx:yy : set dbg zone yy for process
xx\r\n");
wprintf(L" /p=xx?
: get dbg zone of process xx\r\n");
wprintf(L" /m
: list all modules\r\n");
wprintf(L" /m=xx:yy : set dbg zone yy for module
xx\r\n");
wprintf(L" /m=xx?
: get dbg zone of module xx\r\n");
wprintf(L"\r\n");
wprintf(L"Example
: DbgZone.exe /m=httpd.dll?\r\n");
wprintf(L"Example
: DbgZone.exe /m=httpd.dll:0x20\r\n");
}
int _tmain(int argc, _TCHAR* argv[])
{
bool parsingSucceeded = true;
bool listProcesses = false;
bool listModules = false;
wchar_t process[64] = L"";
wchar_t module[64] = L"";
unsigned int zone = 0xFFFFFFFF;
if (argc > 1)
{
for (int i = 1/*skip first arg*/; i < argc; i++)
{
//
/p=xxx
if (_wcsnicmp(argv[i], L"/p", 2) == 0)
{
if (argv[i][2] == L'=')
{
const wchar_t* delimiter = NULL;
const wchar_t* processOption =
&argv[i][3];
delimiter =
wcschr(processOption, L':');
if (delimiter == NULL)
{
delimiter =
wcschr(processOption, L'?');
if (delimiter != NULL)
{
int toCopy = delimiter -
processOption;
wcsncpy(process,
processOption, toCopy);
process[toCopy] = L'\0';
zone = 0xFFFFFFFF;
} else
{
parsingSucceeded = false;
break;
}
} else
{
int toCopy = delimiter -
processOption;
wcsncpy(process,
processOption, toCopy);
process[toCopy] = L'\0';
zone = _wtoi(delimiter
+ 1);
}
} else
{
listProcesses = true;
}
}
//
/m=xxx
else if (_wcsnicmp(argv[i], L"/m", 2) == 0)
{
if (argv[i][2] == L'=')
{
const wchar_t* delimiter = NULL;
const wchar_t* moduleOption =
&argv[i][3];
delimiter =
wcschr(moduleOption, L':');
if (delimiter == NULL)
{
delimiter = wcschr(moduleOption,
L'?');
if (delimiter != NULL)
{
int toCopy = delimiter -
moduleOption;
wcsncpy(module,
moduleOption, toCopy);
module[toCopy] = L'\0';
zone = 0xFFFFFFFF;
} else
{
parsingSucceeded = false;
break;
}
} else
{
int toCopy = delimiter -
moduleOption;
wcsncpy(module,
moduleOption, toCopy);
module[toCopy] = L'\0';
zone = _wtoi(delimiter
+ 1);
}
} else
{
listModules = true;
}
}
// /?
else if (_wcsnicmp(argv[i], L"/?", 2) == 0)
{
wprintf(L"DbgZone
utility to set/get debugzones.\r\n\rn");
PrintHelp();
return 0;
}
// huh,
invalid sequence??
else
{
parsingSucceeded = false;
}
}
}
if (parsingSucceeded == false)
{
wprintf(L"Failed
parsing commandline options.\r\n\r\n");
PrintHelp();
return -1;
}
EnumerateProcessesAndModules();
if (listProcesses)
{
ListProcesses();
return 0;
}
if (listModules)
{
ListModules();
return 0;
}
if ((process[0] != '\0') && (module[0] != '\0'))
{
wprintf(L"Both
exe and dll could not be specified.\r\n");
return -2;
}
if ((process[0] == '\0') && (module[0] == '\0'))
{
wprintf(L"At
least one exe or dll should be specified.\r\n");
return -3;
}
DWORD dwProcessId = GetProcessId(process);
DWORD dwModuleId = GetModuleId(module);
DWORD dwZone = zone;
DBGPARAM dbg;
const wchar_t* item = (process[0] != L'\0') ? process : module;
if ((dwProcessId == 0) && (dwModuleId == 0))
{
wprintf(L"Could
not find process or module '%s'.\r\n", item);
return -4;
}
// Set
(or get)
SetDbgZone(dwProcessId, (LPVOID)dwModuleId,
0, dwZone, &dbg);
// Get
SetDbgZone(dwProcessId, (LPVOID)dwModuleId,
0, 0xFFFFFFFF, &dbg);
wprintf(L"DBGPARAMs
for '%s - %s' are :\r\n", item,
dbg.lpszName);
for (int i = 0; i < 16; i++)
{
wprintf(L" '%s' : %s\r\n", ( (dbg.ulZoneMask & (1 << i)) != 0 ) ? L"On " : L"Off",
dbg.rglpszZones[i]);
}
wprintf(L" ZoneMask = 0x%08X\r\n", dbg.ulZoneMask);
return 0;
}