HOWTO: ISAPI Filter which Logs original Client IP for Load Balanced IIS Servers

Invariably, when you run IIS servers that are load-balanced or forwarded requests behind some other network device, you will find that IIS logs the IP of the network device and not the original client that made the request.

Technically, there is no standard describing how to address/fix this situation, so IIS does not have built-in support for this issue. However, there are some popular private hacks used by several network devices, and here is an ISAPI Filter that allows IIS to easily work with those devices to fix this issue and log the original client IP in IIS.

Question:

Hi,

I need some help!

I have a situtation where I am using a hardware web load balancing device (Netscaler) that changes the IP address that the client HTTP request appears to come from. It also adds an HTTP header to the request (X-Client-IP) that contains the "real" IP addres that the client HTTP request came from.

This is all well and good except that the IIS log files do not contain the right client IP address. I would like to "fix" the log file so that it contains the true client IP.

What I think I need is to write an ISAPI filter that gets the X-Client-IP from the HTTP request and then replace the HTTP IP (pszClientHostName ??) before it gets logged.

Am I on the right track? Is there good example code on how to do something like this? My solution would only need to work for IIS6.

Thanks,

Answer:

Ok, this is one of the more popular behavior requests of IIS which can be easily accomplished with a simple ISAPI Filter which extends the functionality of IIS. So, I went ahead and implemented it, and it is attached at the end of this entry. If you need help compiling it, check out my "sample code" RSS feed for more assistance. My assumption is that if you are able to copy sample code, then you are able to compile it as well as support it yourself.

Behaviorally, this ISAPI Filter is very straight forward.

  1. In SF_NOTIFY_PREPROC_HEADERS, use GetHeader() to retrieve the named request header that is supposed to contain the value of the "original" client IP.
  2. This named request header is actually configurable via an INI file directive, as shown through the GetModuleFileName() and GetPrivateProfileString() Win32 calls. It defaults to "X-Client-IP:" (trailing ':' is important to GetHeader() ).
  3. If the request header exists, then allocate memory using AllocMem() and save it in pFilterContext for retrieval later on in that request's SF_NOTIFY_LOG event.
  4. In SF_NOTIFY_LOG, if pFilterContext != NULL, then it means that the named header was found on the request and pFilterContext contains the new value, so replace pszClientHostName with this value to change what IIS logs. Otherwise, do nothing.

Here are some of the subtle decision points in this filter:

  • I chose to retrieve the request header containing the original client IP using GetHeader() in SF_NOTIFY_PREPROC_HEADERS instead of GetServerVariable() in SF_NOTIFY_LOG because of two reasons:
    1. GetHeader() is able to retrieve any valid request header (including both '-' and '_' characters) on all IIS versions.

    2. GetServerVariable() is NOT able to retrieve valid request headers that contain '-' UNLESS you are running IIS6 and use the documented special HEADER_ prefix

      My goal for this sample filter is for maximum compatibility with all IIS versions. Since I lose nothing with my approach and still retain compatibility, I am choosing the win-win approach. :-)

  • The memory used in changing a IIS log entry is allocated with AllocMem() and NOT new/delete. The reason is because IIS requires this memory to stay valid until it has logged the changed value to disk. This means a stack-based buffer is insufficient because it goes out of scope as soon as SF_NOTIFY_LOG finishes, and managing the lifetime of a new/delete buffer is actually icky (on a per-connection basis, you need to delete this memory after SF_NOTIFY_LOG completes but BEFORE SF_NOTIFY_PREPROC_HEADERS fires again. I cannot think of an event to consistently catch this state). AllocMem() is nice because IIS tracks this memory for you and automatically frees it when its associated connection ends. This matches perfectly with the requirements of modifying log entries and eliminates management of that memory buffer's lifetime. Once again, a win-win situation.
  • pfc->pFilterContext is useful to convey a value generated from one event (SF_NOTIFY_PREPROC_HEADERS) and consumed by a later event (SF_NOTIFY_LOG)

If you want to configure the name of the request header that contains the original client's IP, put the following text into an INI file located in the same directory and named the same as the name of the ISAPI Filter DLL module (i.e. if the Filter DLL is named "LoadBalancedIP.dll", then the text needs to be in a file named "LoadBalancedIP.ini" in that directory). You need to change the MODULE_NAME #define to match the LIBRARY directive in your .def file if you want to control the name of the ISAPI Filter DLL (I am assuming it is called LoadBalancedIP.dll). Yes, this behaves just like URLScan.

 [config]
ClientHostName=New-Header_Name:

This will cause the value of the request header "New-Header_Name:" to be logged as the client IP in the IIS log file, if it exists.

To have changes in the INI file take effect, you need to cause the Filter DLL to reload (i.e. go through GetFilterVersion() again). For IIS6, it means to recycle that worker process; for prior IIS versions, it means to restart the W3SVC service.

Enjoy.

//David

 #include <windows.h>
#include <httpfilt.h>

#define MAX_CLIENT_IP_SIZE              256
#define MODULE_NAME                     "LoadBalancedIP"

TCHAR g_szHeaderName[ MAX_PATH + 1 ];
TCHAR g_szIniPathName[ MAX_PATH + 1 ];

DWORD
OnPreprocHeaders(
    IN HTTP_FILTER_CONTEXT *            pfc,
    IN HTTP_FILTER_PREPROC_HEADERS *    pPPH
);

DWORD
OnLog(
    IN HTTP_FILTER_CONTEXT *            pfc,
    IN HTTP_FILTER_LOG *                pLog
);

BOOL
WINAPI
GetFilterVersion(
    HTTP_FILTER_VERSION *       pVer
    )
/*++

Purpose:

    Required entry point for ISAPI filters.  This function
    is called when the server initially loads this DLL.

Arguments:

    pVer - Points to the filter version info structure

Returns:

    TRUE on successful initialization
    FALSE on initialization failure

--*/
{
    CHAR *                      pCursor = NULL;

    //
    // Locate the config file, if it exists
    //
    GetModuleFileName(
        GetModuleHandle( MODULE_NAME ),
        g_szIniPathName,
        MAX_PATH );
    pCursor = strrchr( g_szIniPathName, '.' );

    if ( pCursor )
    {
        *(pCursor + 1) = '\0';
    }

    //
    // Config file is located with DLL with extension INI
    //
    strcat( g_szIniPathName, "ini" );

    if ( !GetPrivateProfileString( "config",
                                   "ClientHostName",
                                   "X-Client-IP:",
                                   g_szHeaderName,
                                   MAX_PATH,
                                   g_szIniPathName ) )
    {
        SetLastError( ERROR_INVALID_PARAMETER );
        return FALSE;
    }

    pVer->dwFilterVersion = HTTP_FILTER_REVISION;
    lstrcpyn( pVer->lpszFilterDesc,
             "ISAPI Filter to twiddle log entry fields based "
             "on parameterized sources (like request header)",
             SF_MAX_FILTER_DESC_LEN );
    //
    // Technically, I could retrieve the request header from
    // SF_NOTIFY_LOG using GetServerVariable, but that loses
    // flexibility because GetServerVariable cannot retrieve
    // headers that include "_" (underscore) without using
    // IIS6 specific syntax of HEADER_(header-name-as-is).
    //
    // For maximum compatibility (this filter will work from
    // IIS4 on up), I am retrieving the request header from
    // SF_NOTIFY_PREPROC_HEADERS using GetHeader (which can
    // retrieve headers as-is) and changing the log entry
    // in SF_NOTIFY_LOG.
    //
    // This allows me to illustrate common usage case for
    // pFilterContext and pfc->AllocMem(), especially when
    // modifying log fields (the memory must stay valid!!!)
    //
    pVer->dwFlags =
        SF_NOTIFY_ORDER_HIGH |
        SF_NOTIFY_PREPROC_HEADERS |
        SF_NOTIFY_LOG
        ;

    return TRUE;
}

DWORD
WINAPI
HttpFilterProc(
    IN HTTP_FILTER_CONTEXT *            pfc,
    DWORD                               dwNotificationType,
    LPVOID                              pvNotification
    )
/*++

Purpose:

    Required filter notification entry point.  This function is called
    whenever one of the events (as registered in GetFilterVersion) occurs.

Arguments:

    pfc              - A pointer to the filter context for this notification
    NotificationType - The type of notification
    pvNotification   - A pointer to the notification data

Returns:

    One of the following valid filter return codes:
    - SF_STATUS_REQ_FINISHED
    - SF_STATUS_REQ_FINISHED_KEEP_CONN
    - SF_STATUS_REQ_NEXT_NOTIFICATION
    - SF_STATUS_REQ_HANDLED_NOTIFICATION
    - SF_STATUS_REQ_ERROR
    - SF_STATUS_REQ_READ_NEXT

--*/
{
    switch ( dwNotificationType )
    {
    case SF_NOTIFY_PREPROC_HEADERS:
        return OnPreprocHeaders(
            pfc,
            (HTTP_FILTER_PREPROC_HEADERS *) pvNotification );
    case SF_NOTIFY_LOG:
        return OnLog(
            pfc,
            (HTTP_FILTER_LOG *) pvNotification );
    }

    return SF_STATUS_REQ_NEXT_NOTIFICATION;
}

DWORD
OnPreprocHeaders(
    HTTP_FILTER_CONTEXT *           pfc,
    HTTP_FILTER_PREPROC_HEADERS *   pPPH
)
{
    DWORD                           dwRet = SF_STATUS_REQ_NEXT_NOTIFICATION;
    BOOL                            fRet = FALSE;
    CHAR *                          pszBuf = NULL;
    DWORD                           cbBuf = 0;

    SetLastError( NO_ERROR );

    if ( pfc == NULL ||
         pPPH == NULL )
    {
        SetLastError( ERROR_INVALID_PARAMETER );
        goto Finished;
    }

    //
    // Make sure to reset the filter context to NULL for every
    // request so that if we failed to find a named header, we
    // do nothing in SF_NOTIFY_LOG
    //
    pfc->pFilterContext = NULL;

    fRet = pPPH->GetHeader( pfc, g_szHeaderName, pszBuf, &cbBuf );
    if ( fRet == FALSE )
    {
        if ( GetLastError() == ERROR_INVALID_INDEX )
        {
            //
            // The header was not found
            // Ignore and do nothing
            //
            OutputDebugString( "Named header is not found. Do nothing.\n" );
            SetLastError( NO_ERROR );
            goto Finished;
        }
        else if ( GetLastError() == ERROR_INSUFFICIENT_BUFFER &&
                  cbBuf < MAX_CLIENT_IP_SIZE )
        {
            //
            // The header was found and fit size requirements.
            //
            // Let's allocate from IIS's ACache memory which
            // is guaranteed to live as long as the connection,
            // so it is perfect for log entry modification.
            //
            pszBuf = (CHAR *)pfc->AllocMem( pfc, cbBuf, NULL );

            if ( pszBuf == NULL )
            {
                SetLastError( ERROR_NOT_ENOUGH_MEMORY );
                goto Finished;
            }

            fRet = pPPH->GetHeader( pfc, g_szHeaderName, pszBuf, &cbBuf );
            if ( fRet == FALSE )
            {
                goto Finished;
            }

            OutputDebugString( "Named header value is: " );
            OutputDebugString( pszBuf );
            OutputDebugString( "\n" );
        }
        else
        {
            goto Finished;
        }
    }

    //
    // At this point, pszBuf points to the value of named header
    // Just save it and move on.
    //
    pfc->pFilterContext = pszBuf;
    SetLastError( NO_ERROR );

Finished:

    if ( GetLastError() != NO_ERROR )
    {
        OutputDebugString( "Error!\n" );
        dwRet = SF_STATUS_REQ_ERROR;
    }

    return dwRet;
}

DWORD
OnLog(
    IN HTTP_FILTER_CONTEXT *            pfc,
    IN HTTP_FILTER_LOG *                pLog
)
{
    //
    // If the named header was found, set the pszClientHostName
    // log field with its value
    //
    if ( pfc->pFilterContext != NULL )
    {
        pLog->pszClientHostName = (CHAR *)pfc->pFilterContext;
    }

    return SF_STATUS_REQ_NEXT_NOTIFICATION;
}