Talkin' about programmer Error...

I have been making a number of adjustments to the West Wind Web Connection ISAPI DLL recently in relation to how the West Wind Web Connection generated output gets sent back through the ISAPI extension. Most of these changes have been incremental adding very minor functionality, but it touched on some of the core code in the ISAPI dll.

I had put out a new version for testing and Michel Fournier from the Universal Thread kindly notified me that he tried to run the new DLL and had major lockups in his environment a few minutes after installing the new DLL. He’s running Windows 2000 but I’ve been testing on Windows 2003 Server and have not been able to see any lockups even under extreme stress testing loads.

After a few messages back and forth to find out more I decided to install a Windows 2000 Virtual PC instance and check out what’s going on in the same environment as Michel. And sure enough running in COM mode I was able to lock up the IIS instance within a few requests without even stressing the application.

The odd thing is that other than the Header additions nothing in the core had changed. Yet the failure only occurred under COM operation. I pulled out my trusty copy of WinDiff and started to compare what exactly was different. As I suspected other than the header code nothing else in the code had changed. So why this problem only in COM operation and only on Windows 2000/XP but not under Windows 2003?

Well, it turns out I did make a minor code change in the WriteClient() code in the COM output portion. I changed the code to use the bytes returned value from WriteClient() like this:

    while (lnSizeLeft > 0) {

         lnSize=(lnSizeLeft > BUFFER_SIZE) ? BUFFER_SIZE : lnSizeLeft;                                 

         lnWritten=lnSize;

         lnResult=pEcb->WriteClient(pEcb->ConnID,(void *)pszWork,&lnWritten,0);

         pszWork = pszWork + lnWritten;   // jump the buffer pointer

         lnSizeLeft = lnSizeLeft - lnWritten;

      }

Now why I made this change is a mystery to me - because there's nothing that says that this value returns anything even though it is passed by reference. I guess my assumption at the time was that the WriteClient() would perhaps not always write out the full buffer, but only part and we'd come around for another pass to write the rest. It's only natural to assume the &lnWritten value would contain something useful on return... Acck.

This routine basically loops through an incoming string of output and writes it back out into the ISAPI Response stream using WriteClient(). Under IIS 6 this actually works as per my assumption above - every call to WriteClient returns the number of bytes written which usually is the same size as the buffer that is to be written (which I chunk in 16k bits). However, under IIS5 this value does not always return the bytes written. It returns 0 and an error code of 10054 - even though the data gets written out to the Response stream just fine. I also remember in the past that I was told (I think by Wade Hilmo) that the result value from WriteClient() is unreliable and can indicate failure when the call actually worked - this was a big thing in IIS 4 and caused me to ignore any errors which hasn't been a problem.

The ISAPI documentation doesn’t mention that this value is returned with anything, but you gotta wonder why the thing is passed by reference if it doesn't return anything.

Now this was a fun excercise to find. I didn’t even recall making this change and even looking at the difference with WinDiff didn’t immediately point at this very minor code change. Not until I commented out the new method completely and plugged the old, pre-header modification version back in and the problem went away, did I go through the code line by line to see what had changed and find this bug.

It’s good to waste a few hours on some programmer error, ain’t it? At least nowadays debugging ISAPI extensions is a hell of a lot easier than it used to be pre-VS2003. With VS2003 it's as easy as attaching to the IIS worker process and setting a breakpoint. Still C++ code is a piece of work even now that I'm using a C language all the time with C#.

I’m just glad that somebody caught this before it went out into the wild. In the process of debugging this I actually ended up finding another somewhat major bug that caused problems with logins to the Admin pages. It amazes me with the number of users of West Wind Web Connection that nobody has run into this or reported this before...

Oh BTW, for the West Wind Web Connection users among you the updated and fixed version of wc.dll V4.62 is available here:

http://www.west-wind.com/files/updates/wc.zip