排错案例分享
发布时间：2020-12-17 02:45:47 所属栏目：安全 来源：网络整理
导读：前几天另一个组的同事遇到了一个问题,他们的服务器cpu总是很高,用性能监视器看来,情况更是奇怪,开始时cpu一直很低,接着忽然涨到25%,然后再也下不来了,隔一段时间cpu又涨25%,然后就一直保持50%以上,就这样一涨25%,最多涨四次就100%,占用CPU的是w3wp进程,到了1
|
前几天另一个组的同事遇到了一个问题,他们的服务器cpu总是很高,用性能监视器看来,情况更是奇怪,开始时cpu一直很低,接着忽然涨到25%,然后再也下不来了,隔一段时间cpu又涨25%,然后就一直保持50%以上,就这样一涨25%,最多涨四次就100%,占用CPU的是w3wp进程,到了100%的时候,就不得不把w3wp强行终止
除了cpu外其他属性均正常 在性能监视器里添加Asp.net 的Current Request(当前请求数),发现有一些请求始终没有结束,对比cpu的使用率,可以看到当有一个这样的请求,cpu为25%两个则为50%,三个75%.... 看到这个问题,我的第一个反应是请求为什么不过期,而是一直占用cpu,第二个,奇怪的地方,是cpu增长的方式和幅度很有趣,固定每次增长25%,并且增长的时间不定. 开始我没有什么太好的想法,但是光cpu高,其他指标正常,让我觉得起一定有某项工作在努力进行,而且不涉及大量内存和io操作,最简单的模拟方法莫过于写一个什么都不做的死循环,于是我新建了一个web项目,在本机的的iis上建立一个站点指向他,为了真实一些,我还给这个站点单独设置了一个应用程序池,然后,我在一个空页面的onload里加上while(true){}看看效果,下面是访问这个空页面的时候的cpu情况,我们可以看到,占用率超过了50%
还有:对这个页面的请求一直不超时,无论我回收甚至停止应用程序池,w3wp都执着的占用我50%的cpu,而我是一个双核处理器,而有问题的那台是四核的.每次涨25%,呵呵,有点意思哈,是不是实际问题很像了呢? 那么为什么请求不超时呢?本地的代码web.config中设置为debug="true",这时默认是不会超时的,但是发布后一般会改为debug="false",这时才有请求超时,推测另一组的开发人员出于某种原因,发布后没有进行修改.所以造成了一直存在的请求.赶忙叫请人看了看,果然webconfig中debug="true" 但现在的问题是到底是什么请求导致了这些超长时间请求呢?难道真是一个死循环吗? 要解决这个问题,我们首先要找到有问题的请求,开始的时候我们不知道怎么查看iis当前的具体请求,而iis只提供了当前请求数,但是起码我们有iis的日志吧,所以我想使用一个程序来监视cpu的值,一旦发生了25%的长期提升,我就记录下发生的时间,然后到log里面看看对应时间到底有些什么请求,下面就是我的程序,使用的是程序操控performace counter,大概逻辑我会在下面讲述
???
public
?
class
?TestPerformanceTool
????{ ???????? static ?PerformanceCounter?pc; ???????? public ? static ? void ?Test() ????????{ ????????????TimeSpan?span = new ?TimeSpan( 0 , 2 , 0 ); // cpu升高持续多长时间需要记录:现为2分钟 ???????????? int ?interval = 1000 ; // 两次查看cpu使用率的间隔:现为1秒 ???????????? float ?limit = 20f; // cpu升高百分比限制:现为20% ????????????List < TimeValueRecord > ?list? = ? new ?List < TimeValueRecord > (); ????????????pc? = ? new ?PerformanceCounter(); ???????????? // ?获取或设置此性能计数器的性能计数器类别的名称。 ????????????pc.CategoryName? = ? " Processor " ; ???????????? // ?获取或设置与此?PerformanceCounter?实例关联的性能计数器的名称。 ????????????pc.CounterName? = ? " %?Processor?Time " ; ????????????pc.InstanceName? = ? " _Total " ; ????????????pc.ReadOnly? = ? true ; ???????????? float ?pre? = ?0f; ???????????? float ?cur? = ?0f; ???????????? bool ?firstTime? = ? true ; // 排除第一次运行时的跃升干扰 ????????????DateTime?currDate? = ?DateTime.Now; ????????????DateTime?preDate? = ?DateTime.Now; ???????????? float ?diff? = ?0f; ???????????? while ?( true ) ????????????{ ????????????????cur? = ?pc.NextValue(); ???????????????? if ?( ! firstTime) ????????????????{ ????????????????????currDate? = ?DateTime.Now; ????????????????????diff? = ?cur? - ?pre; ???????????????????? if ?(diff? > ?limit) ????????????????????????list.Add( new ?TimeValueRecord(preDate,pre)); ???????????????????? foreach ?(TimeValueRecord?entry? in ?list) ????????????????????{ ???????????????????????? if ?(cur? - ?entry.Value? < ?limit) ????????????????????????????entry.Value? = ? int .MaxValue; // foreach中不能remove,这样就等于使得cur-entry.value为一个负数,肯定小于limit, ???????????????????????? else ? if ?(currDate? - ?entry.Key? > ?span) ????????????????????????{ ????????????????????????????Console.WriteLine( " Jump?Occurred?at?{0} " ,?entry.Key); ????????????????????????????entry.Value? = ? int .MaxValue; // 以免多次输出 ????????????????????????} ????????????????????} ????????????????} ????????????????pre? = ?cur; ????????????????preDate? = ?currDate; ????????????????firstTime? = ? false ; ????????????????Thread.Sleep(interval); ????????????} ????????} ????} ???? internal ? class ?TimeValueRecord ????{ ???????? public ?TimeValueRecord(DateTime?key, float ?value) ????????{ ????????????Key? = ?key; ????????????Value? = ?value; ????????} ???????? public ?DateTime?Key; ???????? public ? float ?Value; ????} 大概逻辑是每隔interval秒查看一次cpu的使用率,如果当前值和上次值之间的差距<25%(程序里用的是20%,为的是灵敏度高一些),就放在一个数组里,注意由于有的时候服务器cpu会出现在一瞬间很高的情况,然后很快降下来的情况,因此,我们还需要知道这次提升是否持续了一段时间,程序里是2分钟,一旦持续超过两分钟,就把这次提升的时间输出,这里简单的输出在了控制台里 写好之后在自己的机器上运行的不错,完全可以监视自己故意制造的cpu使用率持久提升,但是麻烦的是,放在服务器上就没效果了,大概是因为在服务器上,cpu并不是如我想象的瞬间提升,而是有一个过程,我的两次cpu监视的间隔设的是一秒,在这一秒内服务器的cpu没有提高到20%,所以程序就没有捕获,所以只好把间隔调大一些,不过自然输出时间的误差就要大了一些. 不过这时我们的运维人员找到一个很好的工具,微软的 iis诊断工具,可以看到当前请求内容,在这里我提供了一个 下载连接,所以上面我的程序就没有什么用处了,不过可以作为参考,改改的话可以监视很多性能指标的变动时间:) 很快,运维人员就找到了有问题的请求,是一个插入高亮代码的页面,里面代码特简单,实在看不出有死循环,实际这个页面前一天大家曾经怀疑过,但是就是因为里面代码一幕了然,就放过了,我们来看看这个页面的代码
?1?
using
?System; 加上using才37行,本身逻辑不超过14行,不用管具体是干什么用的,只用分析一下这十几行代码,看似没有什么可能造成死循环的地方啊?
?2? using ?System.Data; ?3? using ?System.Configuration; ?4? using ?System.Collections; ?5? using ?System.Web; ?6? using ?System.Web.Security; ?7? using ?System.Web.UI; ?8? using ?System.Web.UI.WebControls; ?9? using ?System.Web.UI.WebControls.WebParts; 10? using ?System.Web.UI.HtmlControls; 11? 12? public ? partial ? class ?InsertCode?:?System.Web.UI.Page 13? { 14? ???? protected ? void ?Page_Load( object ?sender,?EventArgs?e) 15? ????{??????? 16? ???????????? if ?(Request[ " Language " ]? != ? null ) 17? ????????????{ 18? ????????????????HighLightService?s? = ? new ?HighlightService(); 19? ???????????????? bool ?outlining? = ? true ; 20? ???????????????? string ?outText; 21? ???????????????? if ?( string .IsNullOrEmpty(Request[ " outlining " ])) 22? ????????????????????outlining? = ? false ; 23? ???????????????? if ?(Request[ " Code " ]? == ? null ? || ?Request[ " Language " ]? == ? null ) 24? ????????????????????outText? =?s.Transform("public?int?c",?"C#" ,?outlining); 25? ???????????????? else 26? ????????????????????outText? =?s.Transform(Request["Code"],?Request["Language" ],?outlining); 27? ????????????????outText? = ?outText.Replace( " / "" ,? " /// "" ); 28? ????????????????outText? = ?outText.Replace( " /n " ,? " <br> " ); 29? ????????????????outText? = ?outText.Replace( " /r " ,? " <br> " ); 30? ????????????????outText? = ?outText.Replace( " <pre> " ,? "" ); 31? ????????????????outText? = ?outText.Replace( " </pre> " ,? "" ); 32? ????????????????outText? = ?Globals.ReplaceSpace(outText); 33? ????????????????outText? = ? @" <div?style='BORDER-RIGHT:?windowtext?0.5pt?solid;PADDING-RIGHT:?5.4pt;?BORDER-TOP:?windowtext?0.5pt?solid;?PADDING-LEFT:?5.4pt;?BACKGROUND:?#e6e6e6;?PADDING-BOTTOM:?4px;PADDING-TOP:?4px;?????BORDER-LEFT:?windowtext?0.5pt?solid;WIDTH:?95%;????BORDER-BOTTOM:?windowtext?0.5pt?solid;word-break:break-all'> " ? + ?outText? + ? " </DIV> " ; 34? ????????????????clientScript.Text? = ? " var?outText=/ "" ?+?outText?+? " / " ;??FCK.InsertHtml(outText);window.close(); " ; 35? ????????????}???????? 36? ????} 37? } 再仔细看看,代码里有三个方法调用(见加粗的地方那个),前两个经检查是webservice,webservice的站点也不在那台服务器上,所以和cpu高没有关系,其他语句都很简单,不太可能有问题,而后面的一个方法调用很可能就是问题所在的地方了 打开这个方法看看,里面是一个正则替换,也很简单,看来所有的问题就在这个正则上了,读不明白没关系,我也没读明白:P
????????
public
?
static
?
string
?ReplaceSpace(
string
?content)
????????{ ???????????? string ?findstr = " (?<fore>(?:(?:[^<?])*(?:<(?:!--(?:(?:[^-])*(?:(?=-->)|-))*--|(?:[^>])+)>)?)*)[?](?<back>(?:(?:[^<?])*(?:<(?:!--(?:(?:[^-])*(?:(?=-->)|-))*--|(?:[^>])+)>)?)*) " ; ???????????? string ?replacestr = " ${fore} ${back} " ; ???????????? string ?targetstr = System.Text.RegularExpressions.Regex.Replace(content,findstr,replacestr,System.Text.RegularExpressions.RegexOptions.IgnoreCase); ???????????? return ?targetstr; ????????} 显然这个正则并不是所有的情况都有问题,不然后台监视到的cpu占用会厉害的多,所以我找了几段文本去测试,经过反复测试,发现匹配诸如<span>&dll;&dfasfd;&dsd;BB()</span> 这样的代码,会造成死循环(当然也可能是执行时间巨长无比)而在此期间cpu会被占用,内存一切正常下图是我用自己的工具执行匹配时的截图
具体为什么,到底是什么文字模式会导致问题,我还不知道,但是可以肯定的是,问题就在这里了,具体怎么解决,就交给那组的同事了 总结: 身为程序员,通过自己的努力能解决一个问题,心里都是很愉快的,不过高兴之余也应该有所总结,为了自己不被同样的问题再困扰,也为了下次能够更快的找到问题 webconfig中的debug属性,发布时要注意修改,当然保持debug=true,也能让你查看到许多自己程序的问题,所以最好是最初发布时能够把他打开 适应了调试环境,我们在又不能调试,又没法记录日志的时候,需要能静下心来看代码.许多问题通过仔细的阅读和分析代码都能找到. 正则表达式,特别是相对复杂的表达式,一定不要忘记测试其有效性和性能,所以自己最好是手边常备一个习惯的正则工具,我用的是自己写的,下面这个blog上的正则工具比较全面,大家也可以用用看 http://www.cnblogs.com/Heroman/archive/2005/01/13/91265.html 多核服务器处理多线程时,我们可以看到线程和cpu数目之间的直接关系,但不等于说一个线程是由一个cpu全权处理的,具体调度问题我还不太清楚 上面那个正则哪里有问题,大家如果能看出来一定要告诉我 关于排错这篇文章讲的还不错 http://news.csdn.net/n/20071228/112244.html （编辑：李大同） 【声明】本站内容均来自网络，其相关言论仅代表作者个人观点，不代表本站立场。若无意侵犯到您的权利，请及时与联系站长删除相关内容! |
