逍遥一派 发表于 2015-1-14 20:27:20

给大家带来linux内核溃散成绩排查历程总结

如果您觉得本篇CentOSLinux教程讲得好,请记得点击右边漂浮的分享程序,把好文章分享给你的小伙伴们!1.概述
某年某月某日某项目标线上散布式文件体系办事器多台linux体系kernel溃散,严峻影响了某项目对外供应办事的才能,在公司形成了不小影响。经由过程排查线上成绩基础断定了是因为linux内核panic酿成的缘故原由,经由过程两个阶段的成绩排查,基础上断定了linux内核panic的缘故原由。排查询题的次要手腕就是网上查找材料和依据内核毛病日记剖析而且机关前提重现。本文档就是对本人在全部成绩排查过程当中的总结。
2.第一阶段
由于刚呈现成绩的时分人人都对照告急,天天加班都很晚,也制订了良多成绩重现和定位缘故原由的企图。我第一阶段一连保持了两周剖析成绩缘故原由,因为第一阶段本人所做的功效基础上全体构成了具体的剖析文档,以是上面次要总结一下本人在第一阶段都接纳了一些甚么样的办法和抵达了甚么效果。
第一阶段本人也分了几步走,固然开始想到的是重现线上的征象,以是我起首检察了线上的内核毛病日记,依据日记显现次要是qmgr和master两个历程招致的内核panic(最少日记信息是这么提醒的)。固然还分离事先办事器的征象,load对照高,对外不克不及供应办事。以是本人起首想到的就是经由过程写步伐摹拟不休发送邮件(由于qmgr和master历程都与发送邮件相干的历程),当步伐运转起来的时分,本人小小的冲动了一下,就是load上往了,办事器的对外办事才能变慢了(ssh登录),事先的线上靠近线上征象,可是前面内核一向没有panic,哪怕频次在快,并且内核也没有甚么毛病信息。前面垂垂的就扫除了这个缘故原由。
由于堕落的办事器都装置了散布式文件体系,人人就嫌疑是因为散布式文件体系招致了内核panic,可是经由过程察看营业监控信息发明谁人时段散布式文件体系没有甚么特别的信息,并且数据流也不是很年夜。不外我仍是利用几台假造机装置了散布式文件体系,而且写了一个java步伐而且不休的经由过程散布式文件体系客户端写进文件到散布式文件体系集群,同时也把邮件发送步伐启动,只管摹拟线上的情况,跑了良多次很长工夫也没有呈现线上的征象,以是也没有甚么更好的手腕往重现线上的征象了。
因为重现征象失利了,以是只要依据内核的毛病信息间接往剖析缘故原由了。剖析步调很复杂,起首找到堕落的毛病代码,然后剖析高低文相干的代码,剖析的具体历程在客岁的文档也表现出来了。
依据代码的剖析和网上相似的bug基础上定位就是盘算cpu调剂的工夫溢出,招致watchdog历程抛出panic毛病,内核就挂起了。依据剖析定位的缘故原由,我又经由过程修正内核代码往机关工夫溢出的前提,就是经由过程内核模块往修正体系挪用工夫的计数值,修正是乐成了,惋惜内核也间接逝世失落了。以是间接修正内核代码来重现也失利了。
前面也连续征询了良多公司表面熟习内核的手艺职员,他们依据我们供应的信息业给出了本人的剖析,可是也没有很好的重现***和切实的定位毛病缘故原由,并且分歧的人给出的结论差别也对照年夜。
以是第一个阶段一连保持跟踪这个成绩2-3周的工夫也没有一个切实的了局。
3.第二阶段新的一年入手下手了,第一天又入手下手筹办跟踪这个成绩了。一入手下手也制订了复杂的企图,我对本人的企图就是天天5-8点剖析定位内核成绩,固然也特地进修内核相干常识。
这一次一入手下手本人便换了一个角度往思索成绩,客岁是基于单台办事器往剖析内核日记毛病信息,已没有甚么好的体例了。以是筹办同时剖析一切堕落办事器的日记(幸亏之前找运维要了一切堕落办事器的内核日记而且保留上去了,否则怎样逝世的都不晓得),找出他们的配合点。起首他们的配合点就是呈现了trace子体系打印的告诫信息“Deltawaytoobig!…..”的信息,可是依据相干信息,这个是不会招致linux体系挂起的。并且的确我们线上的办事器并非全体都ssh不上往,不外仍是在redhat官方网站找到相似的bug(url:
https://access.redhat.com/knowledge/solutions/70051),而且给出懂得决计划。bug信息息争决计划以下:
whykernelisthrowing“Deltawaytoobig”outwith
WARNING:atkerneltracering_buffer,c:1988rb_reserve_next_event+0x2ce/0×370messages
0Issuekernelisthrowing”Deltawaytoobig”outwithkerneloopsonserver
Environment(情况)
•RedHatEnterpriseLinux6servicepack1
Resolution(办理计划)
Thewarning”Deltawaytoobig”warningmightappearonasystemwithunstableshedclockrightafterthesystemisresumedandtracingwasenabledduringthesuspend.
Sinceit’snotrealybug,andtheunstableschedclockisworkingfastandreliableotherwise,Wesuggestedtokeepusingtheschedclockinanycaseandjusttomakenoteinthewarningitself.ordisablestracingby#echo0>/sys/kernel/debug/tracing/tracing_on
RootCause(基本缘故原由)thiscasewasftraceinvolvedftraceduetotehcalltoftrace_raw_event_power_end(debugfsismountedandftraceloadedinthiscase),theyaretodowithproblemscalculatingatimestampforaringbufferentry.
Messagecomesfromhereandappearstobeindicatingproblemswithtimestability.
1966staticint
1967rb_add_time_stamp(structring_buffer_per_cpu*cpu_buffer,
1968u64*ts,u64*delta)
1969{
1970structring_buffer_event*event;
1971staticintonce;
1972intret;
1973
1974if(unlikely(*delta>(1ULL<<59)&&!once++)){
1975intlocal_clock_stable=1;
1976#ifdefCONFIG_HAVE_UNSTABLE_SCHED_CLOCK
1977local_clock_stable=sched_clock_stable;
1978#endif
1979printk(KERN_WARNING”Deltawaytoobig!%llu”
1980“ts=%lluwritestamp=%llu
%s”,
1981(unsignedlonglong)*delta,
1982(unsignedlonglong)*ts,
1983(unsignedlonglong)cpu_buffer->write_stamp,
1984local_clock_stable?”":
1985“Ifyoujustcamefromasuspend/resume,

1986“pleaseswitchtothetraceglobalclock:

1987”echoglobal>/sys/kernel/debug/tracing/trace_clock
”);
1988WARN_ON(1);
Thiscalledfromrb_reserve_next_event()here.
2122/*
2123*Onlythefirstcommitcanupdatethetimestamp.
2124*Yesthereisaracehere.Ifaninterruptcomesin
2125*justaftertheconditionalandittracestoo,thenit
2126*willalsocheckthedeltas.Morethanonetimestampmay
2127*alsobemade.Butonlytheentrythatdidtheactual
2128*commitwillbesomethingotherthanzero.
2129*/
2130if(likely(cpu_buffer->tail_page==cpu_buffer->commit_page&&
2131rb_page_write(cpu_buffer->tail_page)==
2132rb_commit_index(cpu_buffer))){
2133u64diff;
2134
2135diff=ts-cpu_buffer->write_stamp;
2136
2137/*makesurethisdiffiscalculatedhere*/
2138barrier();
2139
2140/*Didthewritestampgetupdatedalready?*/
2141if(unlikely(ts<cpu_buffer->write_stamp))
2142gotoget_event;
2143
2144delta=diff;
2145if(unlikely(test_time_stamp(delta))){
2146
2147commit=rb_add_time_stamp(cpu_buffer,&ts,&delta);<―-HERE
Thishastodowithtimestampingforringbufferentries.
经由过程下面的信息能够看出,实在和我客岁剖析的代码和体例千篇一律,只是判别缘故原由方面我不敢断定,究竟重现不了,只能是推想。
前面又持续剖析内核中呈现的另外一个毛病,“BUG:softlockupCCPU#Nstuckfor4278190091s!”,对下面的毛病信息我做了一点点处置,CPU#前面的N是对应的一个详细的cpu编号,这个在每台办事器是纷歧样的,另有就是最初中括号中的历程和历程号码分歧,不外就是qmgr和master。以下表格统计:
IP107108109110111112113114选项日记







工夫13:01:2014:03:3414:05:4414:22:4414:19:5814:17:1214:22:49
14:19:58毛病日记范例和历程1qmgr1master
2qmgr1qmgr
2master1qmgr
1qmgr
2master1qmgr
2master1qmgr
2master1qmgr
2master
毛病范例1就是下面提到的不会一同内核挂起的毛病,2就是如今剖析的这个毛病,会招致linux内核panic。能够看出只要107和110事先是没有挂起的。
接着下面的内核堕落日记剖析,发明一个很年夜的不异点,就是4278190091s这个值。起首注释一下这个值代表的意义,一般情形下假如一个cpu凌驾10s没有喂狗(实行watchdog步伐)就会抛出softlockup(软逝世锁)毛病而且挂起内核。可是这个值尽然是4278190091s,并都是一样的。完整能够了解为是一个流动的毛病,为了考证本人的设法,我就在redhat官方网站搜刮这个毛病信息,让我十分冲动的是,尽然找到了不异的bug(url:https://access.redhat.com/knowledge/solutions/68466),然后检察毛病的redhat版本和内核版本,都和我们的一样(redhat6.2和centos6.2对应)。错如信息息争决计划以下:
DoesRedHatEnterpriseLinux6or5havearebootproblemwhichiscausedbysched_clock()overflowaround208.5days?
(Updated21Feb2013,5:11AMGMTRateSelectratingGiveit1/5Giveit2/5Giveit3/5Giveit4/5Giveit5/5CancelratingCancelratingGiveit1/5Giveit2/5Giveit3/5Giveit4/5Giveit5/5.Average:5(1vote).ShowFollow
FollowthispageKCSSolutioncontentKCSSolutioncontentbyMarcMilgramContentinpanicContentinpanicbyMarcMilgramContentin
rhel5Contentinrhel5byMarcMilgramContentinrhel6Contentinrhel6byMarcMilgramContentinkernelContentinkernelby
MarcMilgramContentinRedHatEnterpriseLinuxContentinRedHatEnterpriseLinuxbyMarcMilgramContentinKernel
ContentinKernelbyMarcMilgramContentinVirtualizationContentinVirtualizationbyMarcMilgramContentin
TroubleshootContentinTroubleshootbyMarcMilgramSecondSidebar
0Issue(成绩)
•LinuxKernelpanicswhensched_clock()overflowsafteranuptimeofaround208.5days.
•RedHatEnterpriseLinux6.1systemrebootswithsched_clock()overflowafteranuptimeofaround208.5days
•ThissymptommayhappenonthesystemsusingtheCPUwhichhasTSC.
•AprocessshowingBUG:softlockup-CPU#Nstuckfor4278190091s!
Environment(情况)
•RedHatEnterpriseLinux6
◦RedHatEnterpriseLinux6.0,6.1and6.2areaffected
◦severalkernelsaffected,seebelow
◦TSCclocksource-**seerootcause
•RedHatEnterpriseLinux5
◦RedHatEnterpriseLinux5.3,5.6,5.8:pleaserefertotheresolutionsectionforaffectedkernels
◦RedHatEnterpriseLinux5.0,5,1,5.2,5.4,5.5,5.7:allkernelsaffected
◦RedHatEnterpriseLinux5.9andlaterarenotaffected
◦TSCclocksource-**seerootcause
•Anapproximateuptimeofaround208.5days.
Resolution(办理计划)
•RedHatEnterpriseLinux6
◦RedHatEnterpriseLinux6.x:updatetokernel-2.6.32-279.el6(fromRHSA-2012-0862)orlater.ThiskernelisalreadypartofRHEL6.3GA.Thisfixwasimplementedwith(private)bz765720.
◦RedHatEnterpriseLinux6.2:updatetokernel-2.6.32-220.4.2.el6(fromRHBA-2012-0124)orlater.Thisfixwasimplementedwith(private)bz781974.
◦RedHatEnterpriseLinux6.1ExtendedUpdateSupport:updatetokernel-2.6.32-131.26.1.el6(fromRHBA-2012-0424)orlater.Thisfixwasimplementedwith(private)bz795817.
•RedHatEnterpriseLinux5
◦architecturex86_64/64bit
■RedHatEnterpriseLinux5.x:upgradetokernel-2.6.18-348.el5(fromRHBA-2013-0006)orlater.RHEL5.9GAandlateralreadycontainthisfix.
■RedHatEnterpriseLinux5.8.z:upgradetokernel-2.6.18-308.11.1.el5(fromRHSA-2012-1061)orlater.
■RedHatEnterpriseLinux5.6.z:upgradetokernel-2.6.18-238.40.1.el5(fromRHSA-2012-1087)orlater.
■RedHatEnterpriseLinux5.3.z:upgradetokernel-2.6.18-128.39.1.el5(fromRHBA-2012-1093)orlater.
◦architecturex86/32bit
■RedHatEnterpriseLinux5.x:upgradetokernel-2.6.18-348.el5(fromRHBA-2013-0006)orlater.RHEL5.9GAandlateralreadycontainthisfix.
■RedHatEnterpriseLinux5.8.z:upgradetokernel-2.6.18-308.13.1.el5(fromRHSA-2012-1174)orlater.
■RedHatEnterpriseLinux5.6.z:upgradetokernel-2.6.18-238.40.1.el5(fromRHSA-2012-1087)orlater.
■RedHatEnterpriseLinux5.3.z:upgradetokernel-2.6.18-128.39.1.el5(fromRHBA-2012-1093)orlater.
RootCause(基本缘故原由)
•AninsufficientlydesignedcalculationintheCPUacceleratorinthepreviouskernelcausedanarithmeticoverflowinthesched_clock()function.ThisoverflowledtoakernelpanicoranyotherunpredictabletroubleonthesystemsusingtheTimeStampCounter(TSC)clocksource.
•Thisproblemwilloccuronlywhensystemuptimebecomes208.5daysorexceeds208.5days.
•Thisupdatecorrectstheaforementionedcalculationsothatthisarithmeticoverflowandkernelpaniccannolongeroccurunderthesecircumstances.
•OnRedHatEnterprise5,thisproblemisatimingissueandveryveryraretohappen.
•**SwitchingtoanotherclocksourceisusuallynotaworkaroundformostofcustomersastheTSCisafastaccessclockwhereastheHPETandPMTimerarebothslowaccessclocks.Usingnotscwouldbeasignificantperformancehit.
DiagnosticSteps
Note:
Thisissuecouldlikelyhappeninnumerouslocalsthatdealwithtime
inthekernel.Forexample,auserrunninganon-RedHatkernelhadthe
kernelpanicwithasoftlockupin__ticket_spin_lock.
经由过程下面的信念我们完整能够确认这个是linux内核的一个bug,这个bug的缘故原由下面也信任形貌了,就是关于x86_64系统布局的内核版本,假如启动工夫凌驾208.5天就会招致溢出。
固然失掉了下面的信息证明了内核panic的缘故原由,不外本人想懂得一下淘宝的内核工程师是不是也应当碰到过一样的成绩,以是就在qq上找之前聊过的淘宝内核工程师确认这个成绩。了局证实:他们也碰到过一样的毛病,而且也不克不及重现,办理计划仍是晋级内核版本。
4.总结到此为止基础上已能够确认这个成绩了,排查询题的历程是艰苦的,可是当你终究失掉想要的谜底了你将会是镇静非常,这个和升职加薪没有任何的干系,这个就是手艺的兴趣吧。


如果您觉得本篇CentOSLinux教程讲得好,请记得点击右边漂浮的分享程序,把好文章分享给你的小伙伴们!

灵魂腐蚀 发表于 2015-1-16 18:07:24

给大家带来linux内核溃散成绩排查历程总结

其实当你安装了一个完整的Linux系统后其中已经包含了一个强大的帮助,只是可能你还没有发现和使用它们的技巧。

第二个灵魂 发表于 2015-1-25 22:32:35

现在的linux操作系统如redhat,难点,红旗等,都是用这么一个内核,加上其它的用程序(包括X)构成的。

兰色精灵 发表于 2015-2-4 15:59:12

目前全球有超过一百多个Linux发行版本,在国内也能找到十几个常见版本。如何选择请根据你的需求和能力,RedhatLinux和DebianLinux是网络管理员的理想选择。

愤怒的大鸟 发表于 2015-2-10 04:25:05

其实当你安装了一个完整的Linux系统后其中已经包含了一个强大的帮助,只是可能你还没有发现和使用它们的技巧。

分手快乐 发表于 2015-2-28 21:44:46

清楚了解网络的基础知识,特别是在Linux下应用知识,如接入internet等等。

活着的死人 发表于 2015-3-10 13:04:32

Linux的成功就在于用最少的资源最短的时间实现了所有功能,这也是符合人类进化的,相信以后节能问题会日益突出。

深爱那片海 发表于 2015-3-17 11:10:53

写学习日记,这是学习历程的见证,同时我坚持认为是增强学习信念的法宝。

再见西城 发表于 2015-3-24 11:39:36

Linux的成功就在于用最少的资源最短的时间实现了所有功能,这也是符合人类进化的,相信以后节能问题会日益突出。
页: [1]
查看完整版本: 给大家带来linux内核溃散成绩排查历程总结