ISAPI_Rewrite引起的IIS应用程序池崩溃(fatal communication error)

在园子的发展过程中,曾经遭遇过多次应用程序池崩溃问题(比如:为什么应用程序池总是崩溃),每次都被搞得精疲力尽,后来稀里糊涂地解决了问题,却没找到问题的真正原因。

而这一次,一天内解决了问题并找到了真正原因。这次与以前有什么不同呢?我想主要的不同是面对问题时心态的改变。心态一变,一切随之而变。

在去年阻挡淘宝图片外链造成的巨量请求时(满园尽是503,记曾经的一次IIS 7性能考验),ISAPI_Rewrite曾经立下了汗马功劳,而这次它却是罪魁祸首。一切皆有可能,解决问题时,不要主观地忽视一些因素。

遇到Crash问题,用WinDbg分析dump文件是王道。之前由于觉得它高深、复杂,不敢轻易用它。而这次只用了两个命令,就找到了问题的线索。做一件事情,要从最难、你最害怕的地方着手。

在解决问题的过程中,这篇文章(Debugging Faulting Application w3wp.exe Crashes)给了我很大的帮助,感谢作者Paul White!

下面分享一下问题的解决过程:

一、系统环境

IIS 7.5 + ASP.NET 4 X64 + Managed Pipeline Mode(Integrated) + ISAPI_Rewrite

注:ISAPI_Rewrite是一个进行URL重写的ISAPI Filter。

猜测1:问题可能与应用程序池以集成模式运行有关,IIS用托管程序处理请求,而ISAPI_Rewrite是非托管程序。

猜测2:请求是由System.Web.Hosting.PipelineRuntime转发给ISAPI_Rewrite的。

二、问题的现象

1. 在事件日志中的体现:

Event ID 5011:

A process serving application pool 'cnblogs_com' suffered a fatal communication error with the Windows Process Activation Service. The process id was '10740'. The data field contains the error number.

Event ID 1000:

Faulting application name: w3wp.exe, version: 7.5.7600.16385, time stamp: 0x4a5bd0eb

Faulting module name: ntdll.dll, version: 6.1.7600.16695, time stamp: 0x4cc7b325

Exception code: 0xc0000005

Fault offset: 0x000000000004c8f4

Faulting process id: 0x29f4

Faulting application start time: 0x01cc55c536f78bbc

Faulting application path: c:\windows\system32\inetsrv\w3wp.exe

Faulting module path: C:\Windows\SYSTEM32\ntdll.dll

Report Id: fe796009-c1ba-11e0-85cd-842b2b196be7

Event ID 1001:

Fault bucket , type 0

Event Name: APPCRASH

Response: Not available

Cab Id: 0

Problem signature:

P1: w3wp.exe

P2: 7.5.7600.16385

P3: 4a5bd0eb

P4: ntdll.dll

P5: 6.1.7600.16695

P6: 4cc7b325

P7: c0000005

P8: 000000000004c8f4

P9: 

P10: 

Attached files:

These files may be available here:

C:\ProgramData\Microsoft\Windows\WER\ReportQueue\AppCrash_w3wp.exe_bacc1121e4b19011b4fc1a203d345983b1ae9c_1c835602

Analysis symbol: 

Rechecking for solution: 0

Report Id: fe796009-c1ba-11e0-85cd-842b2b196be7

Report Status: 0

2. 用户访问时的体现:

如果用户在发出请求后服务器响应的过程中发生Crash(这是猜测,不一定准确),浏览器一直处于连接加载状态,直到出现连接超时或连接重置错误。

如果在Crash已发生时,用户发出访问请求,浏览器会显示:The service is unavailable.

Crash发生后,当前W3P进程会重启,这时访问速度会慢。

另外:由于W3P进程会经常重启,也会造成CPU占用偏高。

三、问题分析

从上面的事件日志1001可以看出,发生Crash时,系统会生成dump文件,文件存放的位置就在日志内容中。

运行WinDbg,通过File>Open Crash Dump打开dump文件(比如WER3300.tmp.hdmp),如下图:

在命令框中输入.loadby sos clr,结果如下图:

继续在命令框中输入!clrstack,结果如下:

0:074> !clrstack

...

OS Thread Id: 0x18d0 (74)

Child SP         IP               Call Site

0000000010ccf048 0000000076ddfc6a [NDirectMethodFrameStandalone: 0000000010ccf048] System.Web.Hosting.UnsafeIISMethods.MgdIndicateCompletion(IntPtr, System.Web.RequestNotificationStatus ByRef)

0000000010ccf010 000007fef17bf997 DomainNeutralILStubClass.IL_STUB_PInvoke(IntPtr, System.Web.RequestNotificationStatus ByRef)*** WARNING: Unable to verify checksum for System.Web.ni.dll

*** ERROR: Module load completed but symbols could not be loaded for System.Web.ni.dll

0000000010ccf0e0 000007fef1898994 System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(IntPtr, IntPtr, IntPtr, Int32)

0000000010ccf280 000007fef1898d32 System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(IntPtr, IntPtr, IntPtr, Int32)

0000000010ccf2d0 000007fef1896e51 DomainNeutralILStubClass.IL_STUB_ReversePInvoke(Int64, Int64, Int64, Int32)

0000000010ccf538 000007fef974a7bb [ContextTransitionFrame: 0000000010ccf538] 

从上面的结果看,Crash是在调用System.Web.Hosting.UnsafeIISMethods.MgdIndicateCompletion方法时发生的。

ILSpy查看一下MgdIndicateCompletion的代码:

webengine.dll是什么东东?当时我们没有深究。从这里的代码可以看出这是一个非托管调用,也就是Crash发生在非托管调用时。于是,我们就分析哪些地方会引发非托管调用,能想到的唯一地方就是ISAPI_Rewrite.

同时,我们在网上发现了一篇ISAPI_Rewrite引起应用程序池Crash的文章,而且异常信息显示Crash也是发生在调用System.Web.Hosting.UnsafeIISMethods.MgdIndicateCompletion时。

难道真的是ISAPI_Rewrite引起的?当时从感情上有点不愿接受,它曾经立过汗马功劳!。。。可能由于之前对它的好感,一直把它忽视了,现在它作为怀疑对象突然出现在眼前,虽然感情有些不能接受,但直觉上觉得就是它。

四、问题解决

别无选择!立即撤下ISAPI_Rewrite,换上URL Rewrite module。(当然其中的过程没这么轻松,要改URL重写规则)

自从昨天晚上换过后,事件日志中的错误信息再也没有出现,CPU占用也降下来了,访问页面也没遇到速度慢、连接超时/重置的问题。

我们终于可以欢呼:这一次,我们成功地解决了IIS应用程序池崩溃的问题!

标签: IIS, Crash
posted @ 2011-08-09 11:53 dudu 阅读(3036) 评论(21) 编辑 收藏

 回复 引用 查看   
#1楼 2011-08-09 11:58 今朝-TODAY      
先+1,再漫漫看
 回复 引用 查看   
#2楼 2011-08-09 12:03 librazy      
园长威武~
总算知道怎么用WinDbg调托管了

 回复 引用 查看   
#3楼 2011-08-09 12:06 痴情客      
 回复 引用 查看   
#4楼 2011-08-09 12:08 Jeff Wong      
很好。WinDbg确实无比强大,能帮助发现很多问题。
 回复 引用 查看   
#5楼[楼主] 2011-08-09 12:20 dudu      
@痴情客
关注了。
很多园友提出了很好的建议,反馈了很多问题,我们都认真阅读并记录。真的很感谢大家的热心!
而我们面对的问题要比大家发现的多很多,我们每天的工作就是从众多的问题中选择最重要的,然后集中精力去解决。
身为程序员,大家应该理解问题的解决是一行一行代码写出来的。有些问题看起来简单,但在特定的场景下,处理起来却很困难。

表示,目前的水平还看不懂!
 回复 引用 查看   
#7楼 2011-08-09 12:43 小城故事      
很犀利,要是能找到怎么引起Crash的就更给力了。
 回复 引用 查看   
#8楼[楼主] 2011-08-09 12:55 dudu      
@小城故事
答案在webengine.dll中,但webengine.dll是非托管的,看不到代码。

 回复 引用 查看   
#9楼 2011-08-09 13:15 小城故事      
@dudu
应该有办法看到的,记得微软Web Cast有个课程,讲授.Net源代码,就介绍了String类引用的一些非托管dll的源代码。

 回复 引用 查看   
#10楼 2011-08-09 13:28 whzncut      
赞dudu,亲自上阵解决问题?
支持dudu
 回复 引用 查看   
#12楼 2011-08-09 14:27 duxer      
我现在用的ISAPI_Rewrite3,IIS6,.NET 2.0,没有出现这种错误.
 回复 引用 查看   
#13楼 2011-08-09 14:36 librazy      
@dudu
可以用OllyDBG翻一下webengine.dll

 回复 引用 查看   
#14楼 2011-08-09 15:00 鸽子飞扬      
没看懂,貌似是不明真相的解决了
 回复 引用 查看   
#15楼 2011-08-09 15:25 路过秋天      
感觉和秋色园一样,折腾过后莫名的就好了。
关于这问题的很多起因dudu一个也没介绍:
1:产生的频繁
2:什么情况下产生,引发的可能性是什么?
3:能手动制作出异常情况么
4:产生的原因..直接就直指它了。、

最后直接指定ISAPI_Rewrite有罪是不好的,这样会影响ISAPI_Rewrite在群众的心理影响。
另外得到的结论是?ISAPI_Rewrite不能在iis7下使用?
结论比较模糊,力求真相!

难怪前两天会提示503啊,学习学习。
 回复 引用 查看   
#17楼 2011-08-09 16:50 叶鹏      
貌似我做的通过url实现的自定义三级域名总是应用程序池被挂的原因就在这,一直找不到原因,通过频繁回收程序池来解决,纠结啊,求真相
 回复 引用 查看   
#18楼 2011-08-09 17:48 testzhangsan      
博客园貌似每个月总有那么一天出问题,像女人yuejing一样,呵呵。
 回复 引用 查看   
#19楼 2011-08-10 08:56 木乃伊      
额。。还有这么一说。ISAPI_Rewrite不靠谱?
 回复 引用 查看   
#20楼 2011-08-10 08:56 CR苏杭      
园主威武
 回复 引用 查看   
#21楼 2011-08-25 14:52 偶卖糕的      
貌似我去年也遇到类似的问题,不过是iis6上面,后来一直没解决