Improvements to FastCGI in IIS 7.5

Following improvements have been made to FastCGI module in Win7 (and Win2K8 R2).

1.       Monitor changes to a file

  We have added ability to monitor changes to a file for each FastCGI process pool. Module will recycle FastCGI processes for the process pool if a change to the file is detected. Users can specify file path to monitor using system.webServer/fastCgi/application@monitorChangesTo property. Value can be absolute path to the file or path relative to the folder containing FastCGI executable. In case of php, if fullPath property is set to “c:\php\php-cgi.exe”, monitorChangesTo property can be set to “php.ini” or “c:\php\php.ini”. If file to monitor is not found, status code 500 is returned on each request. Default value of this property is blank which means no file monitoring.      

2.       Real-time tuning

In win2k8, maxInstances property could be configured to a constant value greater than 0. This value dictated maximum number of FastCGI processes which can be launched for each application pool which is also equal to maximum number of requests which can be processed simultaneously as one process handle only one request at a time. Default value of this property was 4. Administrators were required to do some testing with different values to find the optimal number of maxInstances for their server. In win7, if you set maxInstances to 0, FastCGI module automatically adjusts this number up or down every few seconds based on the system load and number of requests waiting in the queue.

3.       Tracing

In win7, STDERR stream can be used to send trace messages to FastCGI module which are logged to IIS FREB trace (if enabled). Trace messages are identified by start markers “IIS_TRACE_INFO:”, “IIS_TRACE_WARNING:”, “IIS_TRACE_ERROR:”. Depending on which start marker is used, information/warning/error trace event is generated. End of a trace statement should be marked by “:IIS_TRACE_END”.  You can send as many trace statements as you like for each request. Most application frameworks running as FastCGI provide a way to send text on STDERR stream. In case of php, function error_log() can be used. So error_log(“IIS_TRACE_WARNING: Warning event.:IIS_TRACE_END”); statement in PHP code will make “Warning event” appear in IIS trace logs. Getting your application traces with traces generated by web server can be a very powerful tool for debugging problems. Note that starting from PHP 5.2.7 you can pass a parameter to the error_log() function to specify that the logged message should be always sent to STDERR regardless of error_log setting in php.ini. To do that use message_type parameter set to 4, e.g. error_log(“IIS_TRACE_WARNING: Warning event.:IIS_TRACE_END”, 4);

4.       STDERR stream handling

FastCGI module can now be configured to handle text sent on STDERR stream differently. In IIS7 we used to return status code 500 and send data received on STDERR stream as the response. Now the behavior can be modified by setting system.webServer/fastCgi/application@stderrMode property. Value of this property can be set to one of following values.

ReturnStderrIn500 – We will set status code 500 and send whatever we receive on STDERR as response. This is the default value and gives same behavior as IIS7.
ReturnGeneric500 – Module will set status code 500 but will return a generic 500. This configuration is useful if you want to enable detailed error logging for server but don’t want to return these errors to users.
IgnoreAndReturn200 – Text on STDERR stream is completely ignored and we will send what we receive on STDOUT as response with status code 200. This property is useful if use debug statements for tracking purposes.
TerminateProcess – FastCGI process will get terminated and generic 500 error message will be returned.

Trace statements are removed from STDERR stream before they are subjected to stderrMode logic. Post Win7 Beta, we are looking into making FastCGI work with CpuLimit feature and also dropping invalid response headers instead of failing requests with 500.

Hope this helps.
Kanwal

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