Event Tracing for Windows Sample

There are already many articles about ETW on the Internet and here are two of them:

Improve Debugging And Performance Tuning With ETW

Common Questions for ETW and Windows Event Log

Here is a prototype C++ class using ETW. Basically the steps of writing and using ETW in an application:

  1. Provide a provider which is responsible for writing logs (events);
  2. A controller is required to create a session, start trace and enable providers. The controller will also specify the repository of events. Controller can be a standard alone utility or built into your application (if the application needs logging all the time);
  3. Events consumer which basically “shows” logged events, e.g. Windows Event Viewer; A meta file (MOF for XP and XML for Vista) may also required by consumer to understand the event;

The C++ class only implemented provider, and it has built-in controller function which will enable logging immediately after registered provider. Issues so far:

  1. There is no meta data provided.
  2. Controller requires administrative privilege. See description regarding ERROR_ACCESS_DENIED in MSDN documentation of  StartTrace.
  3. Although Event Viewer can open ETL file, the general description is a generic message. This may related with meta data and resource file in binary.

 

The header file:

#pragma once

// required definitions and header files

#ifndef _WIN32_WINNT
#define _WIN32_WINNT 0x0500
#endif

#include <atlbase.h>
#include <atlstr.h>
#include <atlcoll.h>

#include <Wmistr.h>
#include <Evntrace.h>

/**
Sample class demonstate ETW event provider and controller under XP
There is a new model for ETW starting from Vista which is not covered here
*/

class CEventLogger
{
public:
    CEventLogger(void);
    virtual ~CEventLogger(void);

    HRESULT Init(LPCTSTR lpszLogFile, LPCTSTR lpszSessionName, GUID *pguid = NULL);
    HRESULT DeInit();
    void Log(UCHAR nLevel, LPCTSTR lpszFormat, …);

protected:
    static ULONG WINAPI ControlCallback(WMIDPREQUESTCODE nRequestCode, PVOID pContext, ULONG* Reserved, PVOID pBuffer);
    ULONG _ControlCallback(WMIDPREQUESTCODE nRequestCode, PWNODE_HEADER pHeader);

    GUID m_provider_guid;
    TRACEHANDLE m_hTrace;
    TRACEHANDLE m_hSession;
    BOOL m_bLoggingEnabled;
    UCHAR m_nLoggingLevel;
    CAtlArray<BYTE> m_eventdata;
    GUID m_session_guid;
    CStringW m_strLogFile;
    CStringW m_strSessionName;
    CAtlArray<BYTE> m_sessiondata;
};

The cpp file:

#include "EventLogger.h"

#include <strsafe.h>
#pragma comment (lib, "strsafe.lib")

CEventLogger::CEventLogger(void) : m_hTrace(0), m_hSession(0), m_bLoggingEnabled(FALSE), m_nLoggingLevel(TRACE_LEVEL_INFORMATION)
{
    memset(&m_provider_guid, 0, sizeof(m_provider_guid));
    memset(&m_session_guid, 0, sizeof(m_session_guid));
}

CEventLogger::~CEventLogger(void)
{
    DeInit();
}

/* Initialize the logger
lpszLogFile:        location of log file, must end with .etl and all folders in path must exists
lpszSessionName:    unique session name, like "<company><module>_trace"
*/
HRESULT CEventLogger::Init(LPCTSTR lpszLogFile, LPCTSTR lpszSessionName, GUID *pguid)
{
    HRESULT hr = S_OK;
    if(NULL == m_hTrace)
    {
        m_strLogFile = lpszLogFile;
        m_strSessionName = lpszSessionName;
        if(m_strLogFile.GetLength() > 0 && m_strSessionName.GetLength() > 0)
        {
            // if caller didn’t supply a GUID we will create one on the fly
            if(NULL == pguid)
                hr = CoCreateGuid(&m_provider_guid);
            else
                memcpy_s(&m_provider_guid, sizeof(m_provider_guid), pguid, sizeof(GUID));

            // register us as event provider
            hr = AtlHresultFromWin32(RegisterTraceGuids(&CEventLogger::ControlCallback, this, &m_provider_guid, NULL, NULL, NULL, NULL, &m_hTrace));
            if(SUCCEEDED(hr))
            {
                m_hSession = NULL;
                m_bLoggingEnabled = FALSE;
                m_nLoggingLevel = TRACE_LEVEL_INFORMATION;

                /**
                Initialize the structure that will be used for writing events, the structure looks like this:
                struct{
                    EVENT_TRACE_HEADER header;
                    MOF_FIELD mof;
                }
                We will use only one MOF_FIELD after the EVENT_TRACE_HEADER and the logging text will be put here
                */
                if(m_eventdata.GetCount() == 0)
                    m_eventdata.SetCount(sizeof(EVENT_TRACE_HEADER) + sizeof(MOF_FIELD));
                if(m_eventdata.GetCount() > 0)
                {
                    memset(m_eventdata.GetData(), 0, m_eventdata.GetCount());
                    PEVENT_TRACE_HEADER pEventHeader = (PEVENT_TRACE_HEADER)m_eventdata.GetData();
                    pEventHeader->Size = m_eventdata.GetCount();
                    pEventHeader->Flags = WNODE_FLAG_USE_MOF_PTR;
                    pEventHeader->Class.Type = EVENT_TRACE_TYPE_INFO;
                }

                /**
                After the provider was registered, we will create a session immediately, start tracing and enable the provider just registered
                */
                hr = CoCreateGuid(&m_session_guid);
                m_sessiondata.SetCount(sizeof(EVENT_TRACE_PROPERTIES) + (m_strLogFile.GetLength() + m_strSessionName.GetLength() + 2) * 2);
                if(m_sessiondata.GetCount() > 0)
                {
                    // Initialize the required data members. Here we will log to file in curcular mode and the maximum file size is 1M (specified by MaximumFileSize)
                    memset(m_sessiondata.GetData(), 0, m_sessiondata.GetCount());
                    PEVENT_TRACE_PROPERTIES pTracePropperties = (PEVENT_TRACE_PROPERTIES)m_sessiondata.GetData();
                    pTracePropperties->Wnode.BufferSize = m_sessiondata.GetCount();
                    pTracePropperties->Wnode.Flags = WNODE_FLAG_TRACED_GUID;
                    pTracePropperties->Wnode.ClientContext = 1;
                    memcpy_s(&pTracePropperties->Wnode.Guid, sizeof(pTracePropperties->Wnode.Guid), &m_session_guid, sizeof(m_session_guid));
                    pTracePropperties->LogFileMode = EVENT_TRACE_FILE_MODE_CIRCULAR | EVENT_TRACE_USE_PAGED_MEMORY;
                    pTracePropperties->MaximumFileSize = 1;
                    pTracePropperties->LogFileNameOffset = sizeof(EVENT_TRACE_PROPERTIES);
                    StringCchCopyW((LPWSTR)((LPBYTE)pTracePropperties + pTracePropperties->LogFileNameOffset), m_strLogFile.GetLength() + 1, m_strLogFile.GetString());
                    pTracePropperties->LoggerNameOffset = pTracePropperties->LogFileNameOffset + (m_strLogFile.GetLength() + 1) * 2;
                    StringCchCopyW((LPWSTR)((LPBYTE)pTracePropperties + pTracePropperties->LoggerNameOffset), m_strSessionName.GetLength() + 1, m_strSessionName.GetString());

                    // start and enable trace
                    hr = AtlHresultFromWin32(StartTrace(&m_hSession, m_strSessionName, pTracePropperties));
                    if(SUCCEEDED(hr))
                        hr = AtlHresultFromWin32(EnableTrace(TRUE, 0, TRACE_LEVEL_VERBOSE, &m_provider_guid, m_hSession));
                }
            }
        }
        else
        {
            hr = E_INVALIDARG;
        }
    }
    return hr;
}

HRESULT CEventLogger::DeInit()
{
    HRESULT hr = S_OK;
    if(NULL != m_hSession)
    {
        // Disable provider
        hr = AtlHresultFromWin32(EnableTrace(FALSE, 0, 0, &m_provider_guid, m_hSession));

        // Stop trace
        hr = AtlHresultFromWin32(ControlTrace(m_hSession, m_strSessionName, (PEVENT_TRACE_PROPERTIES)m_sessiondata.GetData(), EVENT_TRACE_CONTROL_STOP));
    }
    if(NULL != m_hTrace)
    {
        // Unregister provider
        hr = AtlHresultFromWin32(UnregisterTraceGuids(m_hTrace));
        m_hTrace = NULL;
        m_hSession = NULL;
    }
    return hr;
}

void CEventLogger::Log(UCHAR nLevel, LPCTSTR lpszFormat, …)
{
    if(NULL != m_hSession && nLevel <= m_nLoggingLevel && m_eventdata.GetCount() > 0)
    {
        va_list args;
        va_start(args, lpszFormat);
        CString strLog;
        strLog.FormatV(lpszFormat, args);
        va_end(args);

        PEVENT_TRACE_HEADER pEventHeader = (PEVENT_TRACE_HEADER)m_eventdata.GetData();
        PMOF_FIELD pMOF = (PMOF_FIELD)((LPBYTE)pEventHeader + sizeof(EVENT_TRACE_HEADER));

        // Put the string as binary into the first the only MOF structure
        pEventHeader->Class.Level = nLevel;
        pMOF->Length = (strLog.GetLength() + 1) * sizeof(TCHAR);
        pMOF->DataPtr = (ULONG64)strLog.GetString();

        // Write event
        HRESULT hr = AtlHresultFromWin32(TraceEvent(m_hSession, pEventHeader));
    }
}

ULONG WINAPI CEventLogger::ControlCallback(WMIDPREQUESTCODE nRequestCode, PVOID pContext, ULONG* Reserved, PVOID pBuffer)
{
    if(NULL != pContext)
        return ((CEventLogger*)pContext)->_ControlCallback(nRequestCode, (PWNODE_HEADER)pBuffer);
    return ERROR_SUCCESS;
}

// Callback function which responses to logging control from ETW
ULONG CEventLogger::_ControlCallback(WMIDPREQUESTCODE nRequestCode, PWNODE_HEADER pHeader)
{
    if(WMI_ENABLE_EVENTS == nRequestCode)
    {
        m_bLoggingEnabled = TRUE;
        m_hSession = GetTraceLoggerHandle(pHeader);
        if(NULL != m_hSession)
            m_nLoggingLevel = GetTraceEnableLevel(m_hSession);
    }
    else if(WMI_DISABLE_EVENTS == nRequestCode)
    {
        m_bLoggingEnabled = FALSE;
        m_hSession = 0;
    }
    return ERROR_SUCCESS;
}

Advertisements

Posted on January 21, 2010, in Uncategorized. Bookmark the permalink. 3 Comments.

  1. Its like you read my mind! You seem to know a lot about this,
    like you wrote the book in it or something.
    I think that you could do with some pics to drive the message
    home a bit, but other than that, this is excellent blog.
    A fantastic read. I will definitely be back.

  2. Hi there, constantly i used to check blog posts here
    in the early hours in the dawn, because i enjoy to find out more and more.

  3. This is my first time go to see at here and i am truly impressed to
    read all at alone place.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

%d bloggers like this: