When an Unhealthy ISAPI Isn’t Really Unhealthy
Recently, a customer came to me with an interesting issue. While migrating SharePoint 2010 sites from one farm to another, he was seeing errors in the system event log on the target farm similar to the following:
Log Name: System
Source: Microsoft-Windows-WAS
Date: 10/1/2013 3:20:42 PM
Event ID: 5078
Task Category: None
Level: Information
Keywords: Classic
User: N/A
Computer: SP.contoso.com
Description:
An ISAPI reported an unhealthy condition to its worker process. Therefore, the worker process with process id of '2924' serving application pool 'SharePoint Central Administration v4' has requested a recycle.
What was concerning was that he was seeing this for all IIS worker processes associated with SharePoint at the same time. Having seen similar errors in the past, my first instinct was to set up the IIS worker process orphaning feature to try and capture a dump when these happened, so we proceeded to set up a modified version of this against one of the impacted app pools: http://support.microsoft.com/kb/828222. Problem was, no matter what we did, the worker process wouldn’t orphan when this event was logged, so I just had them set up to capture a memory dump when the process shut down. That actually triggered, and we were able to capture a memory dump, but that wasn’t really showing anything useful.
While we were working on this, they happened to mention that the timing of these events correlated with their migration script calling New-SPWebApplication. I did some quick testing here, and discovered that I could reproduce the behavior, but only when I allowed that cmdlet to create a new application pool. If I pointed it at an existing app pool that SharePoint already knew about, no recycle occurred. I freely admit my first instinct was to blame something that SharePoint was doing, but digging further, that was misguided.
What I found is that when SharePoint creates a new application pool in IIS, it adds the name of that new app pool to the preCondition list for the owssvr.dll global module. For example, here’s that globalModules entry in applicationHost.config before I created a new web application in SharePoint:
<globalModules>
...
<add name="SharePoint14Module" image="C:\Program Files\Common Files\Microsoft Shared\Web Server Extensions\14\isapi\owssvr.dll" preCondition="appPoolName=SharePoint Central Administration v4;SharePoint - 80;SharePoint - 8080;" />
...
</globalModules>
Now, after I added a new web application named “SharePoint Test” and had SharePoint create a new application pool for it, I see:
<globalModules>
...
<add name="SharePoint14Module" image="C:\Program Files\Common Files\Microsoft Shared\Web Server Extensions\14\isapi\owssvr.dll" preCondition="appPoolName=SharePoint Central Administration v4;SharePoint - 80;SharePoint - 8080;SharePoint Test" />
...
</globalModules>
Looking in the system event log, I also see the “ISAPI Unhealthy” events for each running SharePoint app pool, indicating a recycle was triggered. As it turns out, this is a by-product of updating the preCondition value. Any change to this for any module that uses preconditions will trigger this behavior based on my testing, as WAS will initiate a recycle of any worker process that has this module loaded so it can pick up the change. It’s unfortunate that IIS has chosen to throw an “ISAPI unhealthy” message in my opinion. Personally, in this case I’d prefer to see this:
An ISAPI reported an unhealthy condition to its worker process. Therefore, the worker process with process id of '2924' serving application pool 'SharePoint Central Administration v4' has requested a recycle.
look something like this:
A change has been detected to the IIS configuration for module owssvr.dll. As a result, the worker process with process id of '2924' serving application pool 'SharePoint Central Administration v4' will recycle to pick up the new value(s).
Regardless, if you happen to notice those events in your system event log when creating a new web application in SharePoint, don’t be alarmed, they’re to be expected if the act of creating the new web app also requires creating a new app pool. And no, I haven’t found a way to disable/postpone the recycles. Even setting disallowRotationOnConfigChange to ‘true’ had no impact on the behavior. I can kinda see why, as a change here could be something that would need to be loaded immediately, but this obviously can pose a challenge to 24/7 shops that have very limited outage windows, so be sure to only make a change like this during slower times to minimize the number of users that are impacted.