Showing posts with label ISAPI. Show all posts
Showing posts with label ISAPI. Show all posts

Thursday, December 21, 2006

QA - COM Initialization and IIS

Question:

Sometimes people (my customers) have a problem with COM Initialization in an ISAPI application. It seems sometimes they do not have to call CoInitializeEx and sometimes they do. Since CoInitializeEx "must" be called prior to using COM and sometimes the isapi works without calling this function, it seems IIS or something else has already called this function.

Can someone tell me, what is IIS's behavior in regard to COM initialization?

Answer:

IIS's behavior in regards to COM initialization is clean - it simply does nothing.

Thus, the behavior you describe sounds like a common bug with some ISAPI DLL running on IIS - calling CoInitializeEx() on threads not owned by the ISAPI. Since IIS reuses threads from its thread pool to call into ISAPI, the following sequence can occur and cause what you observe:

  1. IIS does not call CoInitializeEx() on any of the threads in its thread pool.
  2. IIS uses thread 1 from its thread pool to call the ISAPI entrypoint.
  3. In the entrypoint, ISAPI calls CoInitializeEx() on thread 1 but does not call CoUninitialize() prior to exiting the entrypoint and returning control to IIS.

    thread 1 has now called CoInitializeEx() once.

  4. IIS later uses thread 2 from its thread pool to call the ISAPI entrypoint. Since this thread has never called CoInitializeEx(), thread 2 has called CoInitializeEx() once.
  5. IIS later re-uses thread 1 from its thread pool to call the ISAPI entrypoint.

    thread 1 has now called CoInitializeEx() twice.

At this point, this ISAPI has seriously confused things. There is no way for it to call the correct number of CoUninitialize() on all the IIS threads (suppose the ISAPI entrypoint is never invoked again by IIS - no chance for it to call CoUninitialize() correct number of times, and no way for new user of the same thread to know how many times to call CoUninitialize()). It has tainted the thread pool shared by all other ISAPIs. All sorts of badness can commence at this point.

The simple rule of thumb: do not call CoInitialize()/CoUninitialize() on a thread which you do not own.

//David

Wednesday, December 20, 2006

QA - IIS6 Debugging with NTSD, Setup

Question:

Using some very helpful guidence from this forum, I made my first attempt at trying to catch a problem I see perioidcally in my ISAPI module.

I installed the latest NTSD.EXE and supporting DLL's on the server of interest and loaded them by adding the following registry entry and restarting IIS:

REG ADD "HKLM\Software\Microsoft\Windows NT\CurrentVersion\Image File Execution Options\w3wp.exe" /v Debugger /d "C:\DEBUG\NTSD.EXE -g -G" /t REG_SZ /f

Note I wasn't attempting at this point to monitor remotely as I have RDO access to this server.

NTSD loaded as expected as a process along with W3WP.EXE (as shown in Task Manager). My ISAPI app was exposed to the load overnight and when the morning heavy loads hit, the event log posted the two events shown below. At that point in time, IIS stopped processing requests (although it still seemed to be running). So we removed this server from the WLBS array and began to look for some signs of the debugger's dump.

The problem is I can't find any results from the debugging process. Now this might have been as simple as not having a client running on that server which is monitoring the debug process. But I figured NTSD would throw up some sort of message box indicating a dump was occuring and where. But we didn't see anything like that.

I'm likely missing something obvious in this overall process -- can anyone see what I'm doing wrong?

Event Type: Warning
Event Source: W3SVC
Event Category: None
Event ID: 1010
Date: 12/15/2006
Time: 3:01:16 PM
User: N/A
Computer: DAZLOADBAL3
Description:
A process serving application pool 'DefaultAppPool' failed to respond to a ping.
The process id was '3800'.

Event Type: Information
Event Source: W3SVC
Event Category: None
Event ID: 1082
Date: 12/15/2006
Time: 3:01:16 PM
User: N/A
Computer: DAZLOADBAL3
Description:
A worker process with pid '3800' that serves application pool
'DefaultAppPool' has been determined to be unhealthy (see previous event log
message), but because a debugger is attached to it, the World Wide Web
Publishing Service will ignore the error.

Answer:

Ah, this attempt is correct except for one tiny detail - how to manipulate the debugger when it is auto-attached to an NT Service via Image File Execution Options. Unfortunately, the current situation is unrecoverable, so you will have to start over and account for the missing but critical detail.

Debuggers like CDB, NTSD, and WINDBG from the Microsoft Debugging Toolkit are general purpose debuggers which expect interactive command input to perform tasks like taking a crash dump, disassemble instructions, examine memory, etc. On the other hand, JIT Debuggers like OCA and Dr. Watson are specialized debuggers which automatically perform certain pre-programmed tasks upon triggering.

Common Ways to Manipulate a Debugger

Basically, the question is "now that I have a debugger attached to the process of interest, how do I manipulate the debugger to do what I want?"

The following are some common ways to manipulate a NTSD debugger:

  • Make the debugger command window show up on a WinStation which you can access by launching the debugger interactively as the logged-on user
  • Make the debugger command window show up on a WinStation which you can access by making the NT Service interactive with the Console desktop (WinStation#0)
  • Make the debugger into a "conduit" for an eventual debugging client by piping usermode output into a kernel mode debugger with -d
  • Make the debugger into a "conduit" for an eventual debugging client by opening a TCP/IP port or NamedPipe with -server

The Astute reader should note that there are other debugging methods, such as JIT Debugger, Kernel Debugger, etc... but they are not really relevant nor useful here, so I will skip them for the sake of logical clarity.

Yes, it may seem like a large number of choices for something as simple as "how do I manipulate the debugger", but rest assured, they exist because at one point or another some Microsoft product team needed the feature to debug some aspect of Windows. One may never need to use all of the options, but the utility of having the right option for the right situation means everything in a debugger. Remember, this is the same Debugging Toolkit used within Microsoft to debug native code, so it is plenty powerful when properly wielded.

The Issue, Reformulated

Now that I have enumerated some options, the issue should hopefully make more sense.

  • The NTSD debugger is configured to auto-attach via Image File Execution Options to the W3WP.EXE process launched by an NT Service, which does not interact with the Console desktop by default.
  • An unhandled exception occurred in the W3WP.EXE process, is caught by the attached NTSD debugger (also non-interactive with the Console desktop), and this halts all code execution within the W3WP.EXE process.
  • The NTSD debugger is awaiting commands following the caught exception, but you cannot input them into any debugger commandline window since it is not interacting with the Console Desktop, nor are there any queued commands to the debugger.
  • And since a Windows Process only has one Debugger port, you cannot attach a second debugger via any other method to regain control of the debugger/process...
  • Thus, the current debugging session is inaccessible and dead.
  • To add insult to injury - when W3SVC wants to recycle and/or terminate a monitored W3WP, and it detects that a debugger is already attached onto that W3WP, it will simply skip over taking action against it (i.e. the second event log entry mentioned above). So, not only is the W3WP.EXE halted from executing code and is inaccessible for debugging, IIS also skips cleaning it up.

    This is ok, though, because the feature was added during IIS6 development as a fail-safe against losing W3WP.EXE for investigations. Yes, the behavior looks silly when misconfigured, but the benefits outweigh the occassional mishap.

Corrective Actions

How to address this issue? Well, one can reconfigure the system to support debugging in any of the above ways that I specied earlier. This is how to do each:

  • Make the debugger command window show up on a WinStation which you can access by launching the debugger interactively as the logged-on user

    With the target W3WP.EXE already running, run: C:\DEBUG\NTSD -g -G -p {PID of W3WP.EXE}   If there is only one W3WP.EXE, you can use -pn w3wp.exe to select the unambiguous process name "w3wp.exe" to attach to.

  • Make the debugger command window show up on a WinStation which you can access by making the NT Service interactive with the Console desktop (WinStation#0)

    REG ADD "HKLM\Software\Microsoft\Windows NT\CurrentVersion\Image File Execution Options\w3wp.exe" /v Debugger /d "C:\DEBUG\NTSD.EXE -g -G" /t REG_SZ /f
    SC CONFIG IISADMIN type= share type= interact
    SC CONFIG W3SVC type= own type= interact
    NET STOP /y IISADMIN
    NET START W3SVC

    Be careful with the SC commands - the exact parameters and whitespacing are (unfortunately) important. In particular, neither type=interact, nor type =interact, nor just type= interact work.

    The NTSD window now automatically shows up in WinStation#0 (the local console) for each new W3WP.EXE.

  • Make the debugger into a "conduit" for an eventual debugging client by piping usermode output into a kernel mode debugger with -d

    REG ADD "HKLM\Software\Microsoft\Windows NT\CurrentVersion\Image File Execution Options\w3wp.exe" /v Debugger /d "C:\DEBUG\NTSD.EXE -g -G -d" /t REG_SZ /f

  • Make the debugger into a "conduit" for an eventual debugging client by opening a TCP/IP port or NamedPipe with -server

    • REG ADD "HKLM\Software\Microsoft\Windows NT\CurrentVersion\Image File Execution Options\w3wp.exe" /v Debugger /d "C:\DEBUG\NTSD.EXE -server tcp:port=%d -g -G" /t REG_SZ /f
    • REG ADD "HKLM\Software\Microsoft\Windows NT\CurrentVersion\Image File Execution Options\w3wp.exe" /v Debugger /d "C:\DEBUG\NTSD.EXE -server npipe:pipe=w3wp%d -g -G" /t REG_SZ /f

Conclusion

Which one is "best"? They are all "best" for certain situations and painfully inadequate for the wrong situations... so "best" is really subjective to the debugging task at hand. I recommend evaluating the needs of the debugging situation and then selecting the proper debugging approach that you are comfortable with. While the above list is not conclusive, it should suffice for most debugging situations.

Personally, I favor the -server TCP/IP accessed via a non-console WinStation on the server because it alters no service/server configuration. Yes, the commandline syntax can be complicated, but that's what batch scripting is for. :-)

//David

Thursday, December 07, 2006

QA - On Process, Threading, and DLL Lifetimes

Question:

In a thread "Critical Section shared between ISAPI", David Wang promised a "blog entry about how ISAPI/CGI/ASP.Net binaries load in various IIS versions and configurations".

A serious background about process/thread issues in ISAPI and extension DLL loading/unloading sequence would be very much welcome, because 1) the topic was never covered thoroughly in official docs, 2) things changed in IIS6.

Here are few questions that come to my mind.

* Knowing if my extension will be loaded into one or more process spaces is crucial, because DLL's data will either be shared by instances, or exist as separate copies and this, of course, leads to different synchronization strategy. According to David, I can enforce IIS to keep my extension within one w3wp.exe process, provided I do not use Web Garden. Is this 100% guaranteed? I suspect it is not true on error or overload circumstances.

Let's assume 1st instance of worker process is not responding to ping. Will IIS try politely to terminate 1st instance BEFORE launching the 2nd one? From ISS point of view, 1st instance is inactive and useless, but actually it may still work and use shared resource.

* Is there any occasion for IIS to SUSPEND an extension's thread? (I mean - a thread of one instance, without suspending a thread of another instance). I hope not, because this would play havoc with any concurrency efforts!

* As Ian suggested in the same thread, mutex may solve the problem in case we are afraid of cross-process interaction. Fine, but sometimes we must have a singleton for other reasons than synchronization. My extension, for example, may load about 100-300MB in response to single request. I do not want this stuff to be loaded into memory twice. I need a single process instance - can I be sure?

* IIS5 docs claim that GetExtensionVersion and TerminateExtension functions get called once per DLL's lifetime in IIS space. Was it true? Is this still true in IIS6?

* Is it reasonable and save to spawn a new thread from within an extension? Is it save to leave "something" running between subsequent HTTPExtensionProc calls? (what I did is monitoring/logging thread that performs every 5 seconds or so) How about a timer?

* What is the relation of IIS6 "Application Pool" to Windows API "Thread Pool"?

Answer:

Excellent questions... Sorry I have not yet gotten around to writing that blog entry yet... I have many, many others yet to write. They are all in various stages of construction. Maybe during the upcoming holiday downtime I will find some time to wrap some of them up. But in the meantime, let me attend to your direct questions...

According to David, I can enforce IIS to keep my extension within one w3wp.exe process, provided I do not use Web Garden. Is this 100% guaranteed?

That conclusion is not 100% correct because the devil's in the details. I did not mention the details earlier because the simpler explanation of Web Garden suffices for most people. And... people's eyes usually glaze over when I start on the details, so I try to withhold them unless someone asks for them. ;-)

Now, IIS does NOT have a feature to enforce a "singleton w3wp.exe process loads a given ISAPI Extension DLL" no matter what. However, IIS does have features which when properly configured CAN result in a "singleton w3wp.exe process loading a given ISAPI Extension DLL".

Thus, if you can control IIS Application Pool and ISAPI Execution configuration for the entire server, you can create an environment of a "singleton w3wp.exe process loading a given ISAPI Extension DLL". If you cannot control those configurations for the entire IIS server, then you MUST rely on other mechanisms to ensure your desired behavior.

The following configuration options must be controlled on the entire server to create your desired behavior:

  • DisallowOverlappingRotation - Ensure the replacement w3wp.exe process comes up AFTER the old w3wp.exe terminates.
  • MaxProcesses - Maximum number of w3wp.exe to concurrently service a given Application Pool. Web Garden has a value greater than 1.
  • AppPoolId - The Application Pool which services a given URL namespace. Since Application Pools partition the URL namespace and ISAPI Extensions load and execute inside some partition of the URL namespace serviced by IIS, controlling the Application Pool directly affects the number of times an ISAPI Extension DLL image loads.
  • [Optional]ScriptMaps - Application Mappings determine which ISAPI Extension DLL or CGI EXE execute for any resource types. This configuration is at a per-URL level.
  • The URL itself to invoke the ISAPI Extension DLL.

What you must ensure is that the URL used to invoke your ISAPI Extension DLL, and [optionally] any ScriptMap settings that map that ISAPI Extension DLL, all execute within one specific AppPoolId whose MaxProcesses value is 1 and DisallowOverlappingRotation is TRUE.

Now, I think I shall pause for a moment for the full meaning of the prior sentence to sink in... :-) Yes, there are many possible solution configurations, but they all fit the above criteria.

Of course, if you CANNOT control those IIS configuration values for the entire server, then you CANNOT ensure "singleton w3wp.exe process loads a given ISAPI Extension DLL" and must use other mechanisms. The only alternative I can think of is to load your code into a separate Singleton process on the server and inter-process communicate between it and w3wp.exe.

Will IIS try politely to terminate 1st instance BEFORE launching the 2nd one? From ISS point of view, 1st instance is inactive and useless, but actually it may still work and use shared resource.

IIS behavior depends on the configuration of DisallowOverlappingRotation. If FALSE (default), then IIS will launch the 2nd one before terminating the 1st one. If TRUE, then IIS will launch the 2nd one after the 1st one terminates and stops using shared resources.

* Is there any occasion for IIS to SUSPEND an extension's thread?

No, IIS does not suspend an ISAPI Extension's threads during execution.

* IIS5 docs claim that GetExtensionVersion and TerminateExtension functions get called once per DLL's lifetime in IIS space. Was it true? Is this still true in IIS6?

Yes and Yes. IIS always calls GetExtensionVersion() right after it loads the ISAPI DLL into a given process's memory address space and TerminateExtension() before unloading the ISAPI DLL from memory. In addition, various IIS features affect when an ISAPI DLL is loaded and unloaded.

Unfortunately, most people do not understand when an ISAPI DLL loads/unloads and incorrectly assume IIS guarantees random behavior/properties such as the number of times or timing of when those entry points are invoked... thus leading to confusion between IIS versions. In reality, you just need to understand when and what causes IIS to load/unload an ISAPI DLL.

IIS loads ISAPI Extension DLLs on demand to handle any given request. IIS also caches (i.e. leaves the DLL loaded in memory) the ISAPI Extension DLLs between requests to improve performance. This blog entry details how IIS selects the handler for a given request, so you know how to trigger your ISAPI Extension DLL. And the "Cache ISAPI application" checkbox in the "App Mappings" tab controls whether IIS loads/unloads the ISAPI Extension DLL between every single request, or just load on the first request and unload when the process terminates.

* Is it reasonable and save to spawn a new thread from within an extension? Is it save to leave "something" running between subsequent HTTPExtensionProc calls? (what I did is monitoring/logging thread that performs every 5 seconds or so) How about a timer?

Whether the action is "Reasonable" depends more on the function and design of the ISAPI Extension DLL. IIS places no requirements one way or another.

As for safety - it is safe to spawn your own threads from within an ISAPI Extension - for example, ISAPI Extension using a Thread Pool to queue/process requests asynchronously does this, by design. What you need to ensure is that if those threads touch the ECB (or any other memory, for that matter), that the ECB is valid. For synchronous request, the ECB will not be valid in between HttpExtensionProc calls (its lifetime is tied to the HttpExtensionProc lifetime for that particular request). For asynchronous requests, ECB will stay valid until HSE_REQ_DONE_WITH_SESSION is called on that ECB.

* What is the relation of IIS6 "Application Pool" to Windows API "Thread Pool"?

No direct relation. IIS6 "Application Pool" merely groups process-oriented configuration to partitions of URL namespace. "Thread Pool" is a method of scheduling code execution amongst threads vying for CPU time-slices

//David

Wednesday, November 08, 2006

HOWTO - Update Applications under Debug on IIS 6

Question:

Hi,

we are using a IIS 6.0 server as remote webserver for developing vstudio .NET applications. When debugging we always have to restart IIS (or recycle application pool), in order to overwrite the new compiled DLLs.

The DLL is locked by the w3wp.dll process and the dll therefore cannot be overwritten.

Is there any way to tell IIS (w3wp.dll) not the cache the dll or better free the dll directly after execution?

Answer:

Standard debugging procedures differ depending on the type of application.

ISAPI Extension DLL

You can uncheck the "Cache application files" option under the "App Mappings" tab of the application to force IIS to load/unload the ISAPI Extension DLL for every single request to that resource extension's handler. Be warned that this option is debug-only (do NOT uncheck this on production servers) and often exposes startup/shutdown bugs in your ISAPI Extension DLL.

ISAPI Filter DLL

You should simply recycle the Application Pool(s) which have loaded the Filter DLL. If it is a Global Filter, then you must recycle all Application Pools. If it is a Site Filter, then you must recycle all Application Pools used by applications of the Website which loads that Site Filter.

ASP.Net httpModule and httpHandler

You can dynamically change either the DLL in /bin or source code in global.asax or /App_Code, depending on how you configured the httpModule or httpHandler. No restart/recycle required.

//David

Tuesday, October 31, 2006

QA - ISAPI Extension and Logged Status Code

Question:

Hi,

My ISAPI extension returns "404 xxx" status using

(*ecb->ServerSupportFunction) (ecb->ConnID,
HSE_REQ_SEND_RESPONSE_HEADER_EX,
&vBuffer,
(LPDWORD) NULL,
(LPDWORD) NULL);

but the log file in C:\WINDOWS\SYSTEM32\logfiles\W3SVC1\ex061030.log always shows a status code of 200:

23:00:55 10.10.36.235 GET /bvcgi-bin/michen.dll 200

How to force the log entry to reflect the true status code set by the ISAPI extension?

Thanks for your help!

Answer:

Each ISAPI Extension DLL is responsible for setting the logged HTTP status code for the request it handled. This is done via the dwHttpStatusCode member of the EXTENSION_CONTROL_BLOCK associated with the request. If the ISAPI Extension DLL does not set the HTTP status code, the default value is 200.

Where's the Magic Fairy Dust?

Now, one may be wondering WHY IIS cannot magically set the logged HTTP status code for the ISAPI Extension. After all, it knows the sequence of ServerSupportFunction calls made by ISAPI; why doesn't IIS just "figure out" what gets sent as the response status line and automagically log it?

Well, that behavior assumes that IIS buffers the response data sent by ISAPIs, which then allows IIS to parse the buffered response to determine the actual response status line... and IIS simply does not buffer the response, so it cannot correctly determine the response status line.

For example, suppose you have this sequence of ISAPI function calls:

  1. WriteClient() of "HTTP/1.0 401 Access Denied\r\nContent-Length: 100\r\n\r\n"
  2. HSE_REQ_SEND_RESPONSE_HEADER with a "404 xxx" status

Now, since IIS does not buffer nor parse the response, the WriteClient() data just goes straight to the client. Thus, the client sees a 401 response header with the subsequent 100 bytes (consisting of some part of the "404 xxx" response header) as response entity. Meanwhile, IIS can detect a 404 status line sent by HSE_REQ_SEND_RESPONSE_HEADER. So what should be logged? 401? 404? 200?

If IIS buffered and parsed the response, it would notice that the 401 is the status line preceeding the double \r\n, so it can log the same HTTP status code that the client perceives.

IIS makes no attempt to sort through the above ambiguous situations, so it leaves the choice to the ISAPI making the function calls. After all, the ISAPI should know its effective response status since it must generate the response...

Other Considerations

Now, the ISAPI is responsible for correctly setting the logged HTTP status code for both synchronous and asynchronous IO calls. For synchronous IO calls, the logic is straight forward - make sure to set dwHttpStatusCode on the ECB before returning from HttpExtensionProc.

DWORD WINAPI HttpExtensionProc(
LPEXTENSION_CONTROL_BLOCK pecb
)
{
...
//
// Send 404 response header
//
pecb->ServerSupportFunction(
pecb->ConnID,
HSE_REQ_SEND_RESPONSE_HEADER,
"404 Not Found",
(LPDWORD)NULL,
(LPDWORD)NULL);
//
// log 404 HTTP status code
//
pecb->dwHttpStatusCode = 404;

return HSE_STATUS_SUCCESS;
}

For asynchronous IO calls, the logic is slightly different - make sure to set the dwHttpStatusCode on the ECB in the asynchronous callback function prior to calling HSE_REQ_DONE_WITH_SESSION.

VOID WINAPI * PFN_HSE_IO_COMPLETION AsyncIOCompletionFunction(
LPEXTENSION_CONTROL_BLOCK pecb,
PVOID pContext,
DWORD cbIO,
DWORD dwError
);

DWORD WINAPI HttpExtensionProc(
LPEXTENSION_CONTROL_BLOCK pecb
)
{
HSE_CUSTOM_ERROR_INFO* pErrorInfo = NULL;

...

//
// Setup for asynchronous IO
//
// Create IO objects on heap and make sure its memory
// remains valid throughout the lifetime of the
// asynchronous IO call.
//
pErrorInfo = new HSE_CUSTOM_ERROR_INFO;
if ( NULL == pErrorInfo )
{
goto Finished;
}

ZeroMemory( pErrorInfo, sizeof( HSE_CUSTOM_ERROR_INFO ) );
pErrorInfo->pszStatus = "403 Forbidden";
pErrorInfo->uHttpSubError = 2;
pErrorInfo->fAsync = TRUE;

//
// Keep track of memory used on asynchronous IO call
// with the "context" of the IO Completion function.
//
pecb->ServerSupportFunction(
pecb->ConnID,
HSE_REQ_IO_COMPLETION,
AsyncIOCompletionFunction,
(LPDWORD)NULL,
(LPDWORD)pErrorInfo );

//
// Make the asynchronous IO call.
// - On success, do not touch pErrorInfo and
// immediately return HSE_STATUS_PENDING
// - On failure, immediately cleanup and
// return HSE_STATUS_ERROR
//
if ( pecb->ServerSupportFunction(
pecb->ConnID,
HSE_REQ_SEND_CUSTOM_ERROR,
pErrorInfo,
(LPDWORD)NULL,
(LPDWORD)NULL) )
{
return HSE_STATUS_PENDING;
}

Finished:

if ( NULL != pErrorInfo )
{
delete pErrorInfo;
pErrorInfo = NULL;
}

return HSE_STATUS_ERROR;
}

VOID WINAPI * PFN_HSE_IO_COMPLETION AsyncIOCompletionFunction(
LPEXTENSION_CONTROL_BLOCK pecb,
PVOID pContext,
DWORD cbIO,
DWORD dwError
)
{
HSE_CUSTOM_ERROR_INFO* pErrorInfo = (HSE_CUSTOM_ERROR_INFO*)pContext;
DWORD dwIOStatus = dwError == NO_ERROR ?
HSE_STATUS_SUCCESS :
HSE_STATUS_ERROR;

if ( NULL != pErrorInfo )
{
//
// log HTTP status code
//
pecb->dwHttpStatusCode = atoi( pErrorInfo->pszStatus );

delete pErrorInfo;
pErrorInfo = NULL;
}

pecb->ServerSupportFunction(
pecb->ConnID,
HSE_REQ_DONE_WITH_SESSION,
&dwIOStatus,
(LPDWORD)NULL,
(LPDWORD)NULL );
}

And the tricky one - the asynchronous callback function of HSE_REQ_EXEC_URL. The parent wildcard application mapping which called HSE_REQ_EXEC_URL controls the logged HTTP status code, but that value should come from the execution of the child - you want to log the fact that the child got a 401 during execution and not the fact that the parent reports 200 for being able to transfer execution to the child. Thus, the parent must remember to retrieve the HTTP status code from the child via HSE_REQ_GET_EXEC_URL_STATUS and record that in the dwHttpStatusCode of the parent's ECB in the asynchronous callback.

VOID WINAPI * PFN_HSE_IO_COMPLETION AsyncIOCompletionFunction(
LPEXTENSION_CONTROL_BLOCK pecb,
PVOID pContext,
DWORD cbIO,
DWORD dwError
);

DWORD WINAPI HttpExtensionProc(
LPEXTENSION_CONTROL_BLOCK pecb
)
{
HSE_EXEC_URL_INFO* pExecInfo = NULL;

...

//
// Setup for asynchronous IO
//
// Create IO objects on heap and make sure its memory
// remains valid throughout the lifetime of the
// asynchronous IO call.
//
pExecInfo = new HSE_EXEC_URL_INFO;
if ( NULL == pErrorInfo )
{
goto Finished;
}

ZeroMemory( pExecInfo, sizeof( HSE_EXEC_URL_INFO ) );

//
// Keep track of memory used on asynchronous IO call
// with the "context" of the IO Completion function.
//
pecb->ServerSupportFunction(
pecb->ConnID,
HSE_REQ_IO_COMPLETION,
AsyncIOCompletionFunction,
(LPDWORD)NULL,
(LPDWORD)pErrorInfo );

//
// Make the asynchronous IO call.
// - On success, do not touch pErrorInfo and
// immediately return HSE_STATUS_PENDING
// - On failure, immediately cleanup and
// return HSE_STATUS_ERROR
//
if ( pecb->ServerSupportFunction(
pecb->ConnID,
HSE_REQ_EXEC_URL,
pExecInfo,
(LPDWORD)NULL,
(LPDWORD)NULL) )
{
return HSE_STATUS_PENDING;
}

Finished:

if ( NULL != pExecInfo )
{
delete pExecInfo;
pExecInfo = NULL;
}

return HSE_STATUS_ERROR;
}

VOID WINAPI * PFN_HSE_IO_COMPLETION AsyncIOCompletionFunction(
LPEXTENSION_CONTROL_BLOCK pecb,
PVOID pContext,
DWORD cbIO,
DWORD dwError
)
{
HSE_EXEC_URL_INFO* pExecInfo = (HSE_EXEC_URL_INFO*)pContext;
HSE_EXEC_URL_STATUS ExecStatus;

DWORD dwIOStatus = dwError == NO_ERROR ?
HSE_STATUS_SUCCESS :
HSE_STATUS_ERROR;

if ( pecb->ServerSupportFunction(
pecb->ConnID,
HSE_REQ_GET_EXEC_URL_STATUS,
&ExecStatus,
(LPDWORD)NULL,
(LPDWORD)NULL ) )
{
//
// log HTTP status code
//
pecb->dwHttpStatusCode = ExecStatus.uHttpStatusCode;
}

if ( NULL != pExecInfo )
{
delete pExecInfo;
pExecInfo = NULL;
}

pecb->ServerSupportFunction(
pecb->ConnID,
HSE_REQ_DONE_WITH_SESSION,
&dwIOStatus,
(LPDWORD)NULL,
(LPDWORD)NULL );
}

Conclusion

IIS provides ISAPI a lot of control when it comes to the HTTP status code logged for requests it handles. And with such power comes responsibility...

One final thought... the astute reader should realize that this entire HTTP status code logging scheme has one little flaw since IIS6 - ISAPI is NOT able to manipulate the HTTP SubStatus Code introduced in IIS6. Thus, ISAPI can only log 401.0 but not 401.3, even if it called HSE_REQ_SEND_CUSTOM_ERROR to send the 401.3 custom error. Alas, this flaw will likely remain... unless someone really complains about it. :-)

//David

Tuesday, October 10, 2006

QA - why ECB becomes invalid after returning HSE_STATUS_PENDING

Question:

Hi,

we have a ISAPI extension DLL. This DLL will receive all request for their virtual directory. After processing the request, the resulted HTML or image is sent to the client.

At the moment, the DLL is singlethreaded only (using CSingleLocks to synchronize). But due to multiple request, the DLL should become able to process the request in multiple threads.

Therefore, I overwrote the HttpExtensionProc method of the ISAPI extension class (based on CHttpServer). In HttpExtensionProc I create a CHttpServerContext based on the pECB control structure and save this CHttpServerContext object in a request queue. Then, a message is posted to all threads, that a new request was placed in the queue. The first (idle) thread who receives this message, will read and remove the first item in the request queue (again synchronized by CSingleLock). Meanwhile, my HttpExtensionProc returned HSE_STATUS_PENDING. The ECB control structure should now stay valid until I call ServerSupportFunction with HSE_REQ_DONE_WITH_SESSION for this ECB. But the ECB control structure is invalid when the thread received it from the request queue - it seems that the control structure was released by IIS in spite of returnin HSE_STATUS_PENDING.

This is my HttpExtensionProc:

DWORD CISAPIExtension::HttpExtensionProc(EXTENSION_CONTROL_BLOCK *pECB)
{
if ( strcmp(pECB->lpszMethod, "GET") != 0 )
return CHttpServer::HttpExtensionProc(pECB);

ISAPIENSURE(pECB != NULL);
CHttpServerContext context(pECB);
pECB->dwHttpStatusCode = 0;

if ( !InitInstance(&context) )
{
// ...
return HSE_STATUS_ERROR;
}

return HandleRequest(&context);
}

The HandleRequest method:


DWORD CISAPIExtension::HandleRequest(CHttpServerContext* pCtxt)
{
CString strQuery;
if ( mstrcmp(pCtxt->m_pECB->lpszMethod, "GET") == 0 )
{
strQuery = pCtxt->m_pECB->lpszQueryString;
pCtxt->m_dwBytesReceived = strQuery.GetLength();
}

if ( !IsDataLoaded() )
{
pCtxt->m_dwStatusCode = 500;
pCtxt->m_pECB->dwHttpStatusCode = 500;
LogError(pCtxt->m_pECB->lpszQueryString, 0, _T(
"Could not handle request, because loading data failed!"));
Notify(pCtxt, _T("Internal server error"), _T(
"An error occured while processing your request."
"Check the log file for further details."));
return HSE_STATUS_ERROR;
}

strQuery.MakeLower();
DWORD dwReturn = 0;
// for implementing session based reqest processing
CISAPISession* pSession = NULL;

if ( m_threads.HandleRequest(new CISAPIRequest(pCtxt, pSession)) )
dwReturn = HSE_STATUS_PENDING;
else
dwReturn = HSE_STATUS_ERROR;

return dwReturn;
}

m_threads is the thread manager (including the request queue). The HandleRequest method of m_threads simply adds the CISAPIRequest object (this class has only one constructor and two members: a CHttpServerContext pointer and a Session pointer) to the request queue an posts a notification message to every thread. dwReturn is HSE_STATUS_PENDING in case of success (which is true), so the return value of HttpExtensionProc will be HSE_STATUS_PENDING, too.

When I step through in debugger, my HttpExtesionProc will really return HSE_STATUS_PENDING to the

DWORD WINAPI HttpExtensionProc(EXTENSION_CONTROL_BLOCK *pECB)

method in isapi.cpp. Further debugging isn't possible, as there is no code for the calling method of the HttpExtensionProc in isapi.cpp.

Does anybody has a explanation for this behaviour. Is there any workaround? Maybe I could install a newer IIS SDK, but the solution should run on IIS 5, too.

The solution is MFC based. I'm using Visual Studio 2005 Pro for development and testing, the release version will be built using VS6 SP6. The DLL should work with IIS 5 and 6. I'm testing on WinXP Pro SP2 and IIS 5.1.

Your help is greatly appreciated!

Bye,

Answer:


Actually, I think the issue is within your code. Let me try to explain what is going on and hopefully you will see what is going awry.

The following is my summary of key events from the posted code snippet:

  1. Enter CISAPIExtension::HttpExtensionProc
  2. Create CHttpServerContext on the stack which keeps a pointer to ECB
  3. Create CISAPIRequest on the heap which keeps pointer to CHttpServerContext and CISAPISession
  4. Return HSE_STATUS_PENDING from CISAPIExtension::HttpExtensionProc.

    At this point, stack based memory for CHttpServerContext goes out of scope and becomes invalid. The ECB is still valid, but the memory of the pointer to ECB within CHttpServerContext is invalid.

  5. Later, Thread attempts to use the stored stack-address of CHttpServerContext to retrieve ECB. Since that address is invalid, thread may not get a pointer to an ECB and most likely fails using it.

How to fix this? I can think of a few ways to keep the memory of the pointer to ECB valid through the asynchronous operation, but basically it depends on the memory management scheme of your code:

  • Create CHttpServerContext on the heap, pass it to CISAPIRequest, and let CISAPIRequest free the CHttpServerContext
  • Pass ECB to CISAPIRequest, create CHttpServerContext in the constructor to hold ECB, and let CISAPIRequest free the CHttpServerContext
  • Just pass ECB to CISAPIRequest, keep a pointer to it within CISAPIRequest. Remember to call HSE_REQ_DONE_WITH_SESSION on it when CISAPIRequest no longer needs it

One of the key things to remember for asynchronous processing is to maintain the validity of the memory used throughout the entire asynchronous process. In this case, the code did not maintain the validity of the memory used for CHttpServerContext, which then fails to retain valid pointer to ECB and hence asynchronous processing cannot reliably access the ECB.

This classic failure pattern frequently shows up in the fallowing way: Due to the inherent race condition of using invalid memory, one may find that this code "never failed" while the developer developed/tested with a debug build or under non-stress conditions... and only later, when one is under the gun to produce a retail build for production or stress-test the binary, does the latent error reveal itself.

Frequently, the rigors of questioning one's code or test methodology is not strong or deep enough, and combined with developer's artificial confidence in their code or testing acumen (ahem... hubris, anyone? ;-) ), it leads to claims that either their compiler cannot create bug-free retail code, or that Windows Servers are buggy, or that IIS fails under stress. Basically, anything and anyone but themselves, and Microsoft is a big target.

Personally, when it comes to software development, I check my hubris at the door and start by assuming that I am guilty until proven innocent. And then try really hard to prove my innocence. :-)

//David