Windows Mobile: Some logging tools
If you ever had a windows mobile device that behaved strange you might need some logging to find the cause.
Here is a collection of logging tools I wrote:
BatteryLog
logs the status of battery and power management changes (ie Suspend/Resume etc.)
Instead of just querying the PowerStatusEx the code uses a thread to watch for PowerNotifications
...
// Request power notifications
HANDLE hPowerNotifications = RequestPowerNotifications(hPowerMsgQ,
PBT_TRANSITION |
PBT_RESUME |
PBT_POWERINFOCHANGE);
if (NULL == hPowerNotifications)
{
RETAILMSG(1, (L"RequestPowerNotifications failed: %x\n", GetLastError()));
goto Error;
}
HANDLE rgHandles[2] = {0};
rgHandles[0] = hPowerMsgQ;
rgHandles[1] = g_hEventShutDown;
// Wait for a power notification or for the app to exit
while(WaitForMultipleObjects(2, rgHandles, FALSE, INFINITE) == WAIT_OBJECT_0)
{
DWORD cbRead;
DWORD dwFlags;
POWER_BROADCAST *ppb = (POWER_BROADCAST*) new BYTE[cbPowerMsgSize];
TCHAR* szPPB = new TCHAR[MAX_PATH];
memset(szPPB, 0, MAX_PATH * 2);
TCHAR* szPBtype=new TCHAR[MAX_PATH];
memset(szPBtype, 0, MAX_PATH * 2);
TCHAR szOut[MAX_PATH];
// loop through in case there is more than 1 msg
while(ReadMsgQueue(hPowerMsgQ, ppb, cbPowerMsgSize, &cbRead,
0, &dwFlags))
{
wsprintf(szPPB, L"");
wsprintf(szPBtype, L"");
switch (ppb->Message)
{
case PBT_POWERSTATUSCHANGE:
RETAILMSG(1,(L"Power Notification Message: PBT_POWERSTATUSCHANGE\n"));
wsprintf(szPBtype, L"change: ");
//Add2Log(L"Power Notification Message: PBT_POWERSTATUSCHANGE\n",TRUE);
break;
case PBT_SUSPENDKEYPRESSED:
RETAILMSG(1,(L"Power Notification Message: PBT_SUSPENDKEYPRESSED\n"));
wsprintf(szPBtype, L"keypress: ");
//Add2Log(L"Power Notification Message: PBT_SUSPENDKEYPRESSED\n",TRUE);
break;
...
So the code does not miss changes. But remember, a suspend is signaled at the next resume!
BTmon
logs BT activity of your device. Handles Device connect/disconnect and other events and logs them to a file.
Fortunately MS provides a message queue for BT events too. So the code uses a similar aproach as batteryLog:
void startMsgQueue(HWND hWnd){
DEBUGMSG(1, (L"Entering msgQueue with hwnd=%i\n", hWnd));
MSGQUEUEOPTIONS mqOptions;
memset (&mqOptions, 0, sizeof(mqOptions));
mqOptions.dwFlags = 0;
mqOptions.dwSize = sizeof(mqOptions);
mqOptions.dwMaxMessages = 10;
mqOptions.cbMaxMessage = sizeof(BTEVENT);
mqOptions.bReadAccess = TRUE;
hMsgQ = CreateMsgQueue(NULL, &mqOptions);
if (! hMsgQ) {
nclog(L"Error creating message queue.\n");
goto exit;
}
hBTNotif = RequestBluetoothNotifications(
BTE_CLASS_CONNECTIONS |
BTE_CONNECTION |
BTE_DISCONNECTION |
BTE_ROLE_SWITCH |
BTE_MODE_CHANGE |
BTE_PAGE_TIMEOUT |
BTE_CONNECTION_AUTH_FAILURE |
BTE_CLASS_PAIRING |
BTE_KEY_NOTIFY |
BTE_KEY_REVOKED |
BTE_CLASS_DEVICE |
BTE_LOCAL_NAME |
BTE_COD |
BTE_CLASS_STACK |
BTE_STACK_UP |
BTE_STACK_DOWN
, hMsgQ);
bStop=FALSE;
CreateThread(NULL, 0, msgThread, hWnd, 0, &threadID);
exit:
;
}
...
DWORD msgThread(LPVOID lpParam){
HWND hWnd = (HWND)lpParam;
hwndMsg=hWnd;
DEBUGMSG(1,(L"Waiting for Bluetooth notifications with hwnd=%i...\n", hWnd));
nclog(L"%s: Waiting for Bluetooth notifications...\n", logDateTime());
TCHAR szMsg[MAX_PATH];
wsprintf(szMsg, L"\r\n%s: Waiting for Bluetooth notifications...", logDateTime());
printMsg(szMsg, hWnd);
BTEVENT btEvent;
DWORD dwBytesRead;
DWORD dwFlags;
BOOL fRet;
while (FALSE == bStop) {
DWORD dwWait = WaitForSingleObject (hMsgQ, 5000);//wait up to 5 seconds INFINITE);
switch (dwWait){
case WAIT_OBJECT_0:
// We have got a Bluetooth event!
dwFlags = 0;
dwBytesRead = 0;
fRet = ReadMsgQueue (hMsgQ, &btEvent, sizeof(BTEVENT), &dwBytesRead, 10, &dwFlags);
if (! fRet) {
DEBUGMSG(1,(L"Error - Failed to read message from queue!\n"));
//bStop=TRUE;
}
else {
dumpBTevent(btEvent, hWnd);
}
break;
case WAIT_TIMEOUT:
...
The ‘problem’ with that is that the events contain different data and every type has to be handled very differently. Here is just a small example:
...
void dumpBTevent(BTEVENT btEvent, HWND hwnd){
BT_CONNECT_EVENT* cntEvt = NULL;
BT_DISCONNECT_EVENT* discntEvt=NULL;
BT_ROLE_SWITCH_EVENT* rolSwitchEvt=NULL;
BT_MODE_CHANGE_EVENT* btModeChgEvt=NULL;
BT_LINK_KEY_EVENT* btLnkKeyEvt=NULL;
TCHAR btAddress[18];
TCHAR hConn[12];
TCHAR encMode[5];
TCHAR linkType[5];
TCHAR szTemp[MAX_PATH];
TCHAR szMsg[MAX_PATH];
wsprintf(szMsg, L"\r\n");
switch (btEvent.dwEventId){
case BTE_KEY_NOTIFY:
wsprintf(szMsg, L"\r\n%s: BTE_KEY_NOTIFY:", logDateTime());
break;
case BTE_KEY_REVOKED:
btLnkKeyEvt = (BT_LINK_KEY_EVENT*)btEvent.baEventData;
//XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
wsprintf(btAddress, L"%s", btAddr2Mac( btLnkKeyEvt->bta, btAddress));
wsprintf(szMsg, L"\r\n%s: BTE_KEY_REVOKED: mac=%s", logDateTime(), btAddress);
break;
case BTE_LOCAL_NAME:
wsprintf(szMsg, L"\r\n%s: BTE_LOCAL_NAME:", logDateTime());
break;
...
connMgrLog
log connection manager events and connection state changes.
This logging tool curently does not log to file. The code also uses a notification event supported by the MS ConnMgr API. The background thread receiving the notification message will post another message to update the main window with the current event data:
connStats connectionStates[]={
{L"CONNMGR_STATUS_UNKNOWN", 0x00},
{L"CONNMGR_STATUS_CONNECTED", 0x10 },
{L"CONNMGR_STATUS_SUSPENDED", 0x11 },
{L"CONNMGR_STATUS_DISCONNECTED", 0x20 },
{L"CONNMGR_STATUS_CONNECTIONFAILED", 0x21 },
{L"CONNMGR_STATUS_CONNECTIONCANCELED", 0x22 },
{L"CONNMGR_STATUS_CONNECTIONDISABLED", 0x23 },
{L"CONNMGR_STATUS_NOPATHTODESTINATION", 0x24 },
{L"CONNMGR_STATUS_WAITINGFORPATH", 0x25 },
{L"CONNMGR_STATUS_WAITINGFORPHONE", 0x26 },
{L"CONNMGR_STATUS_PHONEOFF", 0x27 },
{L"CONNMGR_STATUS_EXCLUSIVECONFLICT", 0x28 },
{L"CONNMGR_STATUS_NORESOURCES", 0x29 },
{L"CONNMGR_STATUS_CONNECTIONLINKFAILED", 0x2A },
{L"CONNMGR_STATUS_AUTHENTICATIONFAILED", 0x2B },
{L"CONNMGR_STATUS_WAITINGCONNECTION", 0x40 },
{L"CONNMGR_STATUS_WAITINGFORRESOURCE", 0x41 },
{L"CONNMGR_STATUS_WAITINGFORNETWORK", 0x42 },
{L"CONNMGR_STATUS_WAITINGDISCONNECTION", 0x80 },
{L"CONNMGR_STATUS_WAITINGCONNECTIONABORT", 0x81 },
{NULL, -1},
};
UINT WM_CM_STATUS_CHANGE = WM_USER+1234;
...
void startConnMgrWatch(HWND hWnd){
HRESULT hr;
hEdit=hWnd;
if(WM_CM_STATUS_CHANGE==WM_USER+1234){ // do only once, if 1234 then not registered
WM_CM_STATUS_CHANGE = RegisterWindowMessage( CONNMGR_STATUS_CHANGE_NOTIFICATION_MSG );
//DEBUGMSG(1, (L"RegisterWindowMessage =0x%x.\r\n", WM_CM_STATUS_CHANGE));
logMsg(L"RegisterWindowMessage =0x%x.\r\n", WM_CM_STATUS_CHANGE);
}
// after you registered for the CONNMGR_STATUS_CHANGE_NOTIFICATION_MSG and got a constant you can watch for changes
hr = ConnMgrRegisterForStatusChangeNotification(TRUE, hWnd);
DEBUGMSG(1, (L"ConnMgrRegisterForStatusChangeNotification =0x%x.\r\n", hr));
return;
}
...
void dump_details_params(CONNMGR_CONNECTION_DETAILED_STATUS *p){
//DEBUGMSG(1, (L"\r\n############################################\r\n"));
logMsg(L"\r\n############################################\r\n");
//check which flags are valid and dump them
if(p->dwParams & CONNMGRDETAILEDSTATUS_PARAM_TYPE){ //The dwType member of CONNMGR_CONNECTION_DETAILED_STATUS is valid
//DEBUGMSG(1,(L"\tConnType= '%s'\r\n", szConnType[p->dwType]));
logMsg(L"\tConnType= '%s'\r\n", szConnType[p->dwType]);
}
if(p->dwParams & CONNMGRDETAILEDSTATUS_PARAM_SUBTYPE){ //dwSubtype member of CONNMGR_CONNECTION_DETAILED_STATUS is valid
//DEBUGMSG(1,(L"\tConnSubtype= '%s'\r\n", szConnSubtype[p->dwSubtype]));
logMsg(L"\tConnSubtype= '%s'\r\n", szConnSubtype[p->dwSubtype]);
switch(p->dwSubtype){
case CM_CONNSUBTYPE_UNKNOWN:
break;
}
}
if(p->dwFlags & CONNMGRDETAILEDSTATUS_PARAM_FLAGS){
if(p->dwFlags && CM_DSF_BILLBYTIME){
//DEBUGMSG(1, (L"\t cm_flags+=CM_DSF_BILLBYTIME\r\n"));
logMsg(L"\t cm_flags+=CM_DSF_BILLBYTIME\r\n");
}
if(p->dwFlags && CM_DSF_ALWAYSON){
//DEBUGMSG(1, (L"\t cm_flags+=CM_DSF_ALWAYSON\r\n"));
logMsg(L"\t cm_flags+=CM_DSF_ALWAYSON\r\n");
}
...
void dump_details(CONNMGR_CONNECTION_DETAILED_STATUS *p)
{
dump_details_params(p);
return;
TCHAR txt[MAX_PATH];
if (p->szAdapterName && wcslen(p->szAdapterName)>0){
//DEBUGMSG(1,(L"adap: %s\r\n", p->szAdapterName));
logMsg(L"adap: %s\r\n", p->szAdapterName);
//wsprintf(txt, L"adap: %s\r\n", p->szAdapterName);
//addText(hWndMain, txt);
}
if (p->szDescription){
//DEBUGMSG(1, (L"desc: %s\r\n", p->szDescription));
logMsg(L"desc: %s\r\n", p->szDescription);
//wsprintf(txt, L"desc: %s\r\n", p->szDescription);
//addText(hWndMain, txt);
}
...
deviceMon
(work in progress) watches the device for changes in drivers like connect/disconnect etc.
This logging tool will also use a message queue provided by the MS API set. Here is a small sample watching for a disk change:
...
void MonitorForNewDisks()
{
HANDLE hNotify;
HANDLE qStore ;
DWORD flags;
DWORD size;
BYTE DevDetail[sizeof(DEVDETAIL) + (MAX_PATH * sizeof( TCHAR ))];
DEVDETAIL * pDetail = (DEVDETAIL *)DevDetail;
MSGQUEUEOPTIONS msgopts;
msgopts.dwSize = sizeof(MSGQUEUEOPTIONS);
msgopts.dwFlags = 0;
msgopts.dwMaxMessages = 0;
msgopts.cbMaxMessage = sizeof(DevDetail);
msgopts.bReadAccess = TRUE;
qStore = CreateMsgQueue(NULL, &msgopts);
/*
"IClass"="{f8a6ba98-087a-43ac-a9d8-b7f13c5bae31}"; This is DEVCLASS_STREAM_GUID
In case you follow my suggestion going for CE_DRIVER_SERIAL_PORT_GUID you will need:
"IClass"="{CC5195AC-BA49-48a0-BE17-DF6D1B0173DD}" ; this is CE_DRIVER_SERIAL_PORT_GUID
*/
hNotify = RequestDeviceNotifications(&BLOCK_DRIVER_GUID, qStore, TRUE);
do
{
if(WaitForSingleObject(qStore, 5000) == WAIT_OBJECT_0)
{
while(ReadMsgQueue(qStore, pDetail, sizeof(DevDetail), &size, 1, &flags))
{
if(pDetail->fAttached)
;//do something HandleNewDisk(pDetail->szName);
}
}
} while( !StopMonitoringForNewDisks );
...
memuse: logs the memory usage of all running processes on your device. Possibly find a memory leak in an app.
This logging uses a periodic timer to dump the memory use of all processes. Here it usefull to know that there are a max of 32 processes running. Each process has its own slot and we can walk the slots and query the memory use. Then we need to map the process ID to a process name to get a named list:
...
DWORD getVMuse(){
//build the process list
int iMax = GetProcessNameList((PROCESSNAMES*) &ProcessNames);
DWORD total = 0;
for( int idx = 2; idx < 33; ++idx )
{
PROCVMINFO vmi = { 0 };
if( CeGetProcVMInfo( idx, sizeof( PROCVMINFO ), &vmi ) )
{
//DEBUGMSG(1, ( L"%d: 0x08x %d bytes\r\n", idx, vmi.hProc, vmi.cbRwMemUsed ));
total += vmi.cbRwMemUsed;
//GetProcessIDFromIndex() and match it to the th32ProcessID member of the PROCESSENTRY32 structure
HANDLE dwThreaID = GetProcessIDFromIndex(idx);
for(int i=0; i<iMax; i++){
if(ProcessNames[i]._dwID == (DWORD)dwThreaID)
ProcessNames[i]._memuse = vmi.cbRwMemUsed;
}
}
}
...
showFullScreen
although it is not a real logging tool it can help you to document all windows of a running system. See article at showFullScreen.
All projects can be loaded from logging_ce at github.
http://www.led-mg.de