Generating trace information in native modules

IIS7 has really nice tracing capabilities which are available to all module developers. If you want to make it easy for you and your customers to debug problems in your modules, you should definitely be using them. You can use IHttpTraceContext::RaiseTraceEvent or IHttpTraceContext::QuickTrace in your IIS7 native modules to generate trace information. Once you have your module generating trace information, you or your customers can set trace rules to collect trace data for particular requests.

Simplest way to generate trace events is by using IHttpTraceContext::QuickTrace API. You can get trace context for a particular request using IHttpContext::GetTraceContext and then dump two strings and a HRESULT with a particular verbosity (or trace level) using QuickTrace. Trace level for QuickTrace API can be from 1-7 but you will probably never use values 6, 7 which are for MODULE_START and MODULE_END events. Below is sample code calling QuickTrace.

#include <httptrace.h>

#define TRACE_CRITICAL_ERROR  1
#define TRACE_ERROR           2
#define TRACE_WARNING         3
#define TRACE_INFO            4
#define TRACE_VERBOSE         5

IHttpContext *     pContext…
IHttpTraceContext* pTraceContext = pContext->GetTraceContext();

pTraceContext->QuickTrace(
    L"Invalid data"      // Data1
    L"More Data",          // Data2
    0x8000000D,            // HRESULT
    (UCHAR)TRACE_WARNING); // Trace level

Each trace event requires a trace provider and trace area with which it is associated. When you use QuickTrace, trace provider “WWW Server” and trace area “Module” is used. So for trace events generated by IHttpTraceContext::QuickTrace to appear in trace logs, tracing for provider “WWW Server” and area “Module” must be enabled. If you want to dump information in a more custom format, you can use IHttpTraceContext::RaiseTraceEvent API instead which gives you the maximum flexibility. Types of data which you can dump in a trace event using RaiseTraceEvent are defined by HTTP_TRACE_TYPE enum in httptrace.h. Here is a sample code which generate trace events as generated by QuickTrace using RaiseTraceEvent instead.

HRESULT                  hr            = S_OK;
DWORD                    dwVerbosity   = 3; // Warning
DWORD                    dwArea        = 512;
BOOL                     fTraceEnabled = FALSE;

//
// TraceProviderGuid for WWW Server picked from applicationHost.config
//
static const GUID TraceProviderGuid =
        {0x3a2a4e84,0x4c21,0x4981,{0xae,0x10,0x3f,0xda,0x0d,0x9b,0x0f,0x83}};
static const GUID TraceAreaGuid =
        {0x528dbd54,0x1b68,0x4f58,{0xa8,0xc0,0xb3,0x92,0xdf,0x6d,0xf0,0xc9}};

// IHttpContext*   pContext;
IHttpTraceContext* pTraceContext = pContext->GetTraceContext();

//
// Check if tracing for provider + area is enabled before generating the event
//
HTTP_TRACE_CONFIGURATION TraceConfig;
TraceConfig.pProviderGuid = &TraceProviderGuid;

hr = pTraceContext->GetTraceConfiguration( &TraceConfig );

if( !FAILED(hr) && TraceConfig.fProviderEnabled == TRUE )
{
    if( ( TraceConfig.dwVerbosity >= dwVerbosity ) &&
        ( ( TraceConfig.dwAreas & dwArea ) == dwArea ) )
    {
        fTraceEnabled = TRUE;
    }
}

if( fTraceEnabled == TRUE )
{
    PCWSTR pData1      = L"Invalid data";
    PCWSTR pData2      = L"More data";
    DWORD  dwHresult   = 0x8000000D;

    HTTP_TRACE_EVENT Event;

    Event.dwEvent        = 150;    // Change this number for different events
    Event.pszEventName   = L"SampleModuleTraceEvent";
    Event.cEventItems    = 3;      // count of trace event items
    Event.dwArea         = dwArea;
    Event.dwEventVersion = 1;
    Event.dwVerbosity    = dwVerbosity;
    Event.pAreaGuid      = &TraceAreaGuid;
    Event.pProviderGuid  = &TraceProviderGuid;
    Event.dwFlags        = HTTP_TRACE_EVENT_FLAG_STATIC_DESCRIPTIVE_FIELDS;
    // IIS will set pActivityGuid, pRelatedActivityGuid, Timestamp
    Event.pActivityGuid = NULL;
    Event.pRelatedActivityGuid = NULL;
    Event.dwTimeStamp = 0;

    HTTP_TRACE_EVENT_ITEM TraceItems[ 3 ];
    TraceItems [ 0 ].pszName = L"Data1";
    TraceItems [ 0 ].dwDataType = HTTP_TRACE_TYPE_LPCWSTR;
    TraceItems [ 0 ].pbData = (PBYTE) pData1;
    TraceItems [ 0 ].cbData  = (pData1 == NULL ) ? 0 : (sizeof(WCHAR) * (1 + wcslen(pData1)));
    TraceItems [ 0 ].pszDataDescription = NULL;

    TraceItems [ 1 ].pszName = L"Data2";
    TraceItems [ 1 ].dwDataType = HTTP_TRACE_TYPE_LPCWSTR;
    TraceItems [ 1 ].pbData = (PBYTE) pData2;
    TraceItems [ 1 ].cbData = (pData2 == NULL ) ? 0 : (sizeof(WCHAR) * (1 + wcslen(pData2)));
    TraceItems [ 1 ].pszDataDescription = NULL;

    TraceItems [ 2 ].pszName = L"ErrorCode";
    TraceItems [ 2 ].dwDataType = HTTP_TRACE_TYPE_ULONG;
    TraceItems [ 2 ].pbData = (PBYTE) &dwHresult;
    TraceItems [ 2 ].cbData = 4;
    TraceItems [ 2 ].pszDataDescription = NULL;

    Event.pEventItems = TraceItems;
    pTraceContext->RaiseTraceEvent( &Event );
}

You can point your customers to this article to enable tracing and generate detailed traces. In the code above we used 'WWW Server' trace provider and 'Module' as trace area. If you want to define your own trace provider to group traces from your module, you can define your own trace provider and/or trace area. I will cover that in my next post.

Thanks.
Kanwal

Using IMetadataInfo::GetModuleContextContainer to store configuration data

If you write an IIS7 module, you would typically want to control its behavior based on some configuration data. IIS7 makes it really easy for developers to extend configuration schema so that their customers can put configuration data for their modules with other IIS configuration in applicationHost.config and web.config. Native module developers can then use AhAdmin APIs to read this configuration data. Reading configuration data for each request can be expensive. Developers would typically think of improving the performance by reading the configuration data once and then keeping the data in memory which can be used for other requests. To do this right, you need to worry about following things.

  • Keep unique data only for the paths where configuration changes and not for all possible configuration paths.
  • Detect configuration changes so that module always behave as per the latest configuration.
  • Only delete the configuration data of paths which are affected by the change and not throw everything.
  • Make sure this configuration store is accessed in thread safe manner.

Instead of implementing this from scratch, you can use IMetadata interface available in httpserv.h. Call IHttpContext::GetMetadata() to get IMetadata object which is different for each unique configuration path and then use the IMetadataInfo::GetModuleContextContainer()->SetModuleContext() to store any data you like for your module. Configuration data is a perfect example of kind of data you would like to store for a unique configuration path. Stored data can be retrieved using IMetadataInfo::GetModuleContextContainer()->GetModuleContext(). In addition to making sure that a unique metadata object is available only for paths where configuration changes, IIS will also take care of deleting proper stored contexts when a change notification arrives. Here is how doing this will look like in code.

 

//
// Globals
//
HTTP_MODULE_ID g_pModuleContext = NULL;
IHttpServer *  g_pGlobalInfo    = NULL;

 

HRESULT
WINAPI
RegisterModule(
    DWORD                          dwServerVersion,
    IHttpModuleRegistrationInfo *  pModuleInfo,
    IHttpServer *                  pGlobalInfo
)
{
   

    g_pGlobalInfo    = pGlobalInfo;
    g_pModuleContext = pModuleInfo->GetId( );

   
}

 

class MODULE_CONFIG : public IHttpStoredContext
{
public:

    //
    // Always call this method to get configuration data
    //
   
static
    HRESULT
    GetModuleConfig(
        IHttpContext *   pContext,
        MODULE_CONFIG ** ppModuleConfig
    );

    HRESULT
    Initialize(
        IHttpContext * pContext
    );

    // virtual
    VOID
    CleanupStoredContext(
        VOID
    )
    {
        delete this;
    }

    //
    // Stored Configuration Data
    //
};

 

//static
HRESULT
MODULE_CONFIG::GetModuleConfig(
    IHttpContext *   pContext,
    MODULE_CONFIG ** ppModuleConfig
)
{
    HRESULT                       hr                 = S_OK;
    MODULE_CONFIG *               pModuleConfig      = NULL;
    IHttpModuleContextContainer * pMetadataContainer = NULL;

    pMetadataContainer = pContext->GetMetadata()->GetModuleContextContainer();
    pModuleConfig = (MODULE_CONFIG *)pMetadataContainer->GetModuleContext( g_pModuleContext );

    if ( pModuleConfig != NULL )
    {
        //
        // We found stored data for this module for the metadata
        // object which is different for unique configuration path
        //
        *ppModuleConfig = pModuleConfig;
        return S_OK;
    }

    //
    // If we reach here, that means this is first request or first
    // request after a configuration change IIS core will throw stored context
    // if a change notification arrives for this metadata path
    //
    pModuleConfig = new MODULE_CONFIG();
    if ( pModuleConfig == NULL )
    {
        return E_OUTOFMEMORY;
    }

    //
    // Read module configuration data and store in MODULE_CONFIG
    //
    hr = pModuleConfig->Initialize( pContext );
    if ( FAILED( hr ) )
    {
        pModuleConfig->CleanupStoredContext();
        pModuleConfig = NULL;

        return hr;
    }

 

 

 

 

 

 

 

 

 

    //
    // Store MODULE_CONFIG data as metadata stored context
    //
    hr = pMetadataContainer->SetModuleContext( pModuleConfig,
                                               g_pModuleContext );
    if ( FAILED( hr ) )
    {
        pModuleConfig->CleanupStoredContext();
        pModuleConfig = NULL;

        //
        // It is possible that some other thread stored context before this thread
        // could do. Check returned hr and return context stored by other thread
        //
        if ( hr == HRESULT_FROM_WIN32( ERROR_ALREADY_ASSIGNED ) )
        {
            *ppModuleConfig = (MODULE_CONFIG *)pMetadataContainer->GetModuleContext( g_pModuleContext );
            return S_OK;
        }
    }

    *ppModuleConfig = pModuleConfig;
    return hr;
}

 

HRESULT
MODULE_CONFIG::Initialize(
    IHttpContext * pContext
)
{
    HRESULT                hr               = S_OK;
    IAppHostAdminManager * pAdminManager    = NULL;
    IAppHostElement *      pAppHostElement  = NULL;
    BSTR                   bstrSectionName  = NULL;
    BSTR                   bstrConfigPath   = NULL;

   

 

 

 

 

 

 

 

 

 

 

    pAdminManager = g_pGlobalInfo->GetAdminManager();
   

    //
    // Read configuration data at metapath of IMetadataInfo object
    //
    bstrConfigPath = SysAllocString( pContext->GetMetadata()->GetMetaPath() );
   

    hr = pAdminManager->GetAdminSection( bstrSectionName,
                                         bstrConfigPath,
                                         &pAppHostElement);
   
}

 

Hope this helps.
Kanwal