Advanced logging module which media team released few days ago uses IIS tracing subsystem and allow module developers to log custom data in W3C compatible format using familiar IHttpTraceContext interface. If you are a module developer and want to generate W3C style logs for requests with custom data, doing it with advanced logging module is very easy. All you need to do is call IHttpTraceContext::RaiseTraceEvent passing data you want to publish. Your module installer can then configure advanced logging module to make it dump this data in a log file and you have complete logging solution without ever have to deal with log files yourself. Let’s see what it takes to make use of this functionality.

Generating trace information in your module

I have a simple class below which hides some of the complexity of IIS tracing subsystem. You can use most of the code below directly in your module. Just change area GUID and also code under RaiseEvent to dump your own custom data.

#include <httpserv.h>
#include <httptrace.h>

//
// Start of the new provider class AdvancedLoggingTraceProvider,
//
// GUID: {f41fdbf7-1b0a-45e9-9666-2918b0a9d144}
// NOTE:
// You must use this provider GUID for advanced logging to
// process events generated by your module
//
// Description: IIS: Advanced Logging
//
class AdvancedLoggingTraceProvider
{
public:
    static
    LPCGUID
    GetProviderGuid(
        VOID
    )
    {
        static const GUID AdvLoggingProviderGuid =
          {0xf41fdbf7,0x1b0a,0x45e9,{0x96,0x66,0x29,0x18,0xb0,0xa9,0xd1,0x44}};
        return &AdvLoggingProviderGuid;
    };

    enum enumAreaFlags
    {
        IISAdvancedLoggingGeneral = 0x0000
    };

    static
    LPCWSTR
    TranslateEnumAreaFlagsToString(
        enum enumAreaFlags EnumValue
    )
    {
        switch( (DWORD) EnumValue )
        {
            case 0x0000: return L"IISAdvancedLoggingGeneral";
        }
        return NULL;
    };

    static
    BOOL
    CheckTracingEnabled(
        IHttpTraceContext * pHttpTraceContext,
        enumAreaFlags       AreaFlags,
        DWORD               dwVerbosity
    )
    {
        HRESULT                  hr;
        HTTP_TRACE_CONFIGURATION TraceConfig;
        TraceConfig.pProviderGuid = GetProviderGuid();
        hr = pHttpTraceContext->GetTraceConfiguration( &TraceConfig );
        if ( FAILED( hr )  || !TraceConfig.fProviderEnabled )
        {
            return FALSE;
        }
        if ( TraceConfig.dwVerbosity >= dwVerbosity &&
             (  TraceConfig.dwAreas == (DWORD) AreaFlags || 
             ( TraceConfig.dwAreas & (DWORD)AreaFlags ) == (DWORD)AreaFlags ) )
        {
            return TRUE;
        }
        return FALSE;
    };
};

//
// Start of the new event class IISAdvancedLoggingGeneralEvents
// GUID: {ffa89186-ec59-42c1-988f-bbbd0ee48d4f}
// Use any random area GUID
// Description: Advanced Logging general events
//
class IISAdvancedLoggingGeneralEvents
{
public:
    static LPCGUID GetAreaGuid( VOID )
    {
        static const GUID AreaGuid =
          {0xffa89186,0xec59,0x42c1,{0x98,0x8f,0xbb,0xbd,0x0e,0xe4,0x8d,0x4f}};
        return &AreaGuid;
    };

    class SAMPLE_TRACE_EVENT
    {
    public:
        static
        HRESULT
        RaiseEvent(
            IHttpTraceContext * pHttpTraceContext,
            LPCGUID      pContextId,
            LPCWSTR      pSample_Data1,
            LPCWSTR      pSample_Data2
        )
        {
            HTTP_TRACE_EVENT Event;
            Event.pProviderGuid  = AdvancedLoggingTraceProvider::GetProviderGuid();
            Event.dwArea         =  AdvancedLoggingTraceProvider::IISAdvancedLoggingGeneral;
            Event.pAreaGuid      = IISAdvancedLoggingGeneralEvents::GetAreaGuid();
            Event.dwEvent        = 1;
            Event.pszEventName   = L"SAMPLE_TRACE_EVENT";
            Event.dwEventVersion = 1;
            Event.dwVerbosity    = 0;
            Event.cEventItems    = 6;
            Event.pActivityGuid  = NULL;
            Event.pRelatedActivityGuid = NULL;
            Event.dwTimeStamp    = 0;
            Event.dwFlags        = HTTP_TRACE_EVENT_FLAG_STATIC_DESCRIPTIVE_FIELDS;

            // pActivityGuid, pRelatedActivityGuid, Timestamp to be filled in by IIS

            HTTP_TRACE_EVENT_ITEM Items[ 3 ];
            Items[ 0 ].pszName = L"ContextId";
            Items[ 0 ].dwDataType = HTTP_TRACE_TYPE_LPCGUID; // mof type (object)
            Items[ 0 ].pbData = (PBYTE) pContextId;
            Items[ 0 ].cbData = 16;
            Items[ 0 ].pszDataDescription = NULL;
            Items[ 1 ].pszName = L"Sample_Data1";
            Items[ 1 ].dwDataType = HTTP_TRACE_TYPE_LPCWSTR; // mof type (string)
            Items[ 1 ].pbData = (PBYTE) pSample_Data1;
            Items[ 1 ].cbData  =
                 ( Items[ 1 ].pbData == NULL )? 0 : ( sizeof(WCHAR) * (1 + (DWORD) wcslen( (PWSTR) Items[ 1 ].pbData  ) ) );
            Items[ 1 ].pszDataDescription = NULL;
            Items[ 2 ].pszName = L"Sample_Data2";
            Items[ 2 ].dwDataType = HTTP_TRACE_TYPE_LPCWSTR; // mof type (string)
            Items[ 2 ].pbData = (PBYTE) pSample_Data2;
            Items[ 2 ].cbData  =
                 ( Items[ 2 ].pbData == NULL )? 0 : ( sizeof(WCHAR) * (1 + (DWORD) wcslen( (PWSTR) Items[ 2 ].pbData  ) ) );
            Items[ 2 ].pszDataDescription = NULL;

            Event.pEventItems = Items;
            pHttpTraceContext->RaiseTraceEvent( &Event );

            return S_OK;
        };

        static
        BOOL
        IsEnabled(
            IHttpTraceContext *  pHttpTraceContext
        )
        {
            return AdvancedLoggingTraceProvider::CheckTracingEnabled(
                                 pHttpTraceContext,
                                 AdvancedLoggingTraceProvider::IISAdvancedLoggingGeneral,
                                 0 );
        }
    };
};

Once you have class(es) similar to SAMPLE_TRACE_EVENT defined for the event(s) you want to generate, you can just call RaiseEvent in your module. Before generating the event you should call IsEnabled() to check if a relevant trace provider is present with tracing enabled. Here is what you will write in your module.

IHttpTraceContext* pTraceContext = pContext->GetTraceContext();

if( IISAdvancedLoggingGeneralEvents::SAMPLE_TRACE_EVENT::IsEnabled( pTraceContext ) == TRUE )
{
    IISAdvancedLoggingGeneralEvents::SAMPLE_TRACE_EVENT::RaiseEvent( pTraceContext,
                                                                     NULL,
                                                                     “Data1”,
                                                                     “Data2” );
}

Configuring advanced logging to generate logs 


Now to dump data generated by your module in advanced logging logs, you need to create log definition and specify event names as field names in advanced logging configuration. To do this, follow the steps as below in advanced logging UI.

1.       Go to advanced logging UI and create a new log definition.

2.       Specify details and then add additional fields which your module is generating. In the sample above these are Sample_Data1 and Sample_Data2. As advanced logging require a unique name to identify the event uniquely, we recommend people to use “<ModuleName>_” as prefix in the event names.

3.       Restart w3svc (this requirement will be removed in the next release of advanced logging).

That’s it. Log file produced will have single entry for each request received by the server. If a request gets short circuited and never reaches your module code where you generate the trace event, Sample_Data1 and Sample_Data2 field values will be blank strings. To log only requests which reached your module’s RaiseEvent call, make Sample_Data1 and Sample_Data2 fields “required” in advanced logging configuration. Note that ability to mark a field “required” is not there in the UI yet. You can edit the IIS configuration file manually or you other tools like appcmd, configuration editor to do it. More detailed steps to configure advanced logging are available here.

Hope this helps.
Kanwal