Logging Call Stacks with CeLog (Windows Embedded CE 6.0)

1/5/2010

You can use the CeLog functions together with kernel functions to log call stack information for any thread. Note that Kernel Tracker does not store call stack events. If you are logging call stack events, you should use CeLogFlush.exeor OSCapture.exeto flush the data.

To log a call stack

1. Turn on CELZONE_PROCESS and CELZONE_LOADER to make sure that CeLog records the memory locations for processes and DLLs.

   If CELZONE_PROCESS and CELZONE_LOADER are turned off, CeLog does not record the process and loader addresses. As a result, the CeLog tools cannot map process and loader addresses to symbol addresses. In order to look up the symbols that make sense of the callstack data, these zones must be enabled.

2. Retrieve the call stack of the desired thread using GetThreadCallStack.

3. Call CeLogDatato log the call stack information gathered in step 2, using the event ID CELID_CALLSTACK.

To minimize performance degradation

• To minimize the performance degradation that querying the stack might cause, consider logging only after verifying that CeLog is loaded, using IsCeLogStatus. If CeLog is not loaded, the code takes no action.

  - or -

  Log only after determining that a specific zone such as CELZONE_MISC is enabled, using IsCeLogZoneEnabled with (CELZONE_xxx). If the specified zone is not enabled, the code takes no action.

To guard against modifications

• To guard against modifications that GetThreadCallStack might make, preserve the LastError value. Call GetLastError to get the value before calling GetThreadCallStack, and SetLastError to restore the value after you are done.

Example

The following example uses CeLogDataand kernel functions to retrieve stack frame information for a particular thread, and logs the information to the CeLog buffer.

#include "pkfuncs.h"
#include "celog.h"
__inline static void
MyLogStackFunc(
{
    \\ Check to see if CeLog is enabled. If not, stop now
    if (IsCeLogStatus(CELZONE_ENABLED_ANY)) {

        \\ Set up the structure that holds the stack.
        \\ This example uses 20 frames to keep stack usage low.
        #define MY_STACK_BUFFER_LEN 20
        CallSnapshot cs[MY_STACK_BUFFER_LEN];

        \\## IMPORTANT ## Preserve lasterr value while capturing callstack
        DWORD dwLastError = GetLastError();
        DWORD dwNumFrames, dwFramesLogged;
        dwFramesLogged = 0;
        do {
            \\ Get the stack for the current thread
            dwNumFrames = GetThreadCallStack(
                (HANDLE) GetCurrentThreadId(),
                MY_STACK_BUFFER_LEN, cs, 0, dwFramesLogged);

            if (dwNumFrames) {
                \\ Log the stack information as a CeLog event
                CeLogData(TRUE, CELID_CALLSTACK, (PVOID) cs,
                    (WORD)(dwNumFrames * sizeof(CallSnapshot)),
                    0, CELZONE_ALWAYSON, 0, FALSE);
                dwFramesLogged += dwNumFrames;
            }

            // Keep looping if there are more than 20 stack frames,
            // logging a callstack event for every 20 frames.
        } while (dwNumFrames == MY_STACK_BUFFER_LEN);

        SetLastError(dwLastError);
    }
}

To resolve symbols and have Readlog show the functions that correspond to each address in the call stack, use Readlog with the -v command-line parameter. For more information, see Readlog Command-Line Options.

The following example shows Readlog output from MyLogStackFunc. Callstack events are displayed following a header line that contains the words Callstack (from previous event).

Because the call stack for this module was larger than the 20-frame limit set in MyLogStackFunc, the stack is logged as two events.

0:23:51.823.311 : Callstack (from previous event):
     0x03F6B658 coredll.dll!xxx_GetThreadCallStack
     0x09A05530 afd.dll!MyLogStackFunc
     0x09A05370 afd.dll!DeleteSocket
     0x09A054BC afd.dll!SockDeref
     0x09A06C4C afd.dll!AfdClose
     0x8014B18C NK.EXE!DoCloseAPIHandle
     0x03061834 wspm.dll!WSPCloseSocket
     0x03AE8338 dtpt_lsp.dll!?WSPCloseSocket@DPROVIDER
     0x03AE4934 dtpt_lsp.dll!?WSPCloseSocket@CLSPSocketPassthrough
     0x03AE2284 dtpt_lsp.dll!?WSPCloseSocket
     0x03857428 autobind_lsp.dll!?WSPCloseSocket
     0x03857CD4 autobind_lsp.dll!?WSPCloseSocket@CLSPSocketPassthrough
     0x03852344 autobind_lsp.dll!?WSPCloseSocket
     0x03304048 ssllsp.dll!?WSPCloseSocket
     0x03301DFC ssllsp.dll!?WSPCloseSocket
     0x02E02410 ws2.dll!closesocket
     0x02E07460 ws2.dll!IsIp6Running
     0x02E07CB8 ws2.dll!getaddrinfo
     0x03472C4C ipv6hlp.dll!GetAddrInfoW
     0x03473CAC ipv6hlp.dll!SetIsatapRouterAddress
 0:23:51.825.524 : Callstack (from previous event):
     0x03474E0C ipv6hlp.dll!Add6to4Address
     0x03475430 ipv6hlp.dll!ProcessInterfaceStateChange
     0x03475778 ipv6hlp.dll!OnChangeInterfaceInfo
     0x03471DCC ipv6hlp.dll!WaitForSingleObjectThread
     0x03F6CD14 coredll.dll!ThreadBaseFunc
 

See Also

Other Resources

Logging Your Own CeLog Events
CallSnapshot
GetLastError
GetThreadCallStack
GetCurrentThreadId
CeLogData
CeLog Event Identifiers
CeLog Zones