Linux系統(tǒng)內(nèi)核崩潰如何排查？

　　Linux內(nèi)核如果奔潰，將導(dǎo)致Linux系統(tǒng)kernel崩潰，自己的電腦還好，如果是公司的電腦將造成不小的損失，下面小編就給大家介紹下Linux系統(tǒng)內(nèi)核崩潰的排查方法，一起來(lái)了解下吧。

　　1.概述

　　某年某月某日某項(xiàng)目的線上分布式文件系統(tǒng)服務(wù)器多臺(tái)linux系統(tǒng)kernel崩潰，嚴(yán)重影響了某項(xiàng)目對(duì)外提供服務(wù)的能力，在公司造成了不小影響。通過(guò)排查線上問(wèn)題基本確定了是由于linux內(nèi)核panic造成的原因，通過(guò)兩個(gè)階段的問(wèn)題排查，基本上確定了linux內(nèi)核panic的原因。排查問(wèn)題的主要手段就是網(wǎng)上查找資料和根據(jù)內(nèi)核錯(cuò)誤日志分析并且構(gòu)造條件重現(xiàn)。本文檔就是對(duì)自己在整個(gè)問(wèn)題排查過(guò)程中的總結(jié)。

　　2.第一階段

　　因?yàn)閯偝霈F(xiàn)問(wèn)題的時(shí)候大家都比較緊急，每天加班都很晚，也制定了很多問(wèn)題重現(xiàn)和定位原因的計(jì)劃。我第一階段連續(xù)堅(jiān)持了兩周分析問(wèn)題原因，由于第一階段自己所做的功能基本上全部形成了詳細(xì)的分析文檔，所以下面主要總結(jié)一下自己在第一階段都采取了一些什么樣的措施以及到達(dá)了什么效果。

　　第一階段自己也分了幾步走，當(dāng)然最先想到的是重現(xiàn)線上的現(xiàn)象，所以我首先查看了線上的內(nèi)核錯(cuò)誤日志，根據(jù)日志顯示主要是qmgr和master兩個(gè)進(jìn)程導(dǎo)致的內(nèi)核panic（至少日志信息是這么提示的）。當(dāng)然還結(jié)合當(dāng)時(shí)服務(wù)器的現(xiàn)象，load比較高，對(duì)外不能提供服務(wù)。所以自己首先想到的就是通過(guò)寫程序模擬不斷發(fā)送郵件（因?yàn)閝mgr和master進(jìn)程都與發(fā)送郵件相關(guān)的進(jìn)程），當(dāng)程序運(yùn)行起來(lái)的時(shí)候，自己小小的激動(dòng)了一下，就是load上去了，服務(wù)器的對(duì)外服務(wù)能力變慢了（ssh登錄），當(dāng)時(shí)的線上接近線上現(xiàn)象，但是后面內(nèi)核一直沒(méi)有panic，哪怕頻率在快，而且內(nèi)核也沒(méi)有什么錯(cuò)誤信息。后面漸漸的就排除了這個(gè)原因。

　　因?yàn)槌鲥e(cuò)的服務(wù)器都安裝了分布式文件系統(tǒng)，大家就懷疑是由于分布式文件系統(tǒng)導(dǎo)致了內(nèi)核panic，但是通過(guò)觀察業(yè)務(wù)監(jiān)控信息發(fā)現(xiàn)那個(gè)時(shí)段分布式文件系統(tǒng)沒(méi)有什么特殊的信息，而且數(shù)據(jù)流也不是很大。不過(guò)我還是使用幾臺(tái)虛擬機(jī)安裝了分布式文件系統(tǒng)，并且寫了一個(gè)java程序并且不斷的通過(guò)分布式文件系統(tǒng)客戶端寫入文件到分布式文件系統(tǒng)集群，同時(shí)也把郵件發(fā)送程序啟動(dòng)，盡量模擬線上的環(huán)境，跑了很多次很長(zhǎng)時(shí)間也沒(méi)有出現(xiàn)線上的現(xiàn)象，所以也沒(méi)有什么更好的手段去重現(xiàn)線上的現(xiàn)象了。

　　由于重現(xiàn)現(xiàn)象失敗了，所以只有根據(jù)內(nèi)核的錯(cuò)誤信息直接去分析原因了。分析步驟很簡(jiǎn)單，首先找到出錯(cuò)的錯(cuò)誤代碼，然后分析上下文相關(guān)的代碼，分析的詳細(xì)過(guò)程在去年的文檔也體現(xiàn)出來(lái)了。

　　根據(jù)代碼的分析和網(wǎng)上類似的bug基本上定位就是計(jì)算cpu調(diào)度的時(shí)間溢出，導(dǎo)致watchdog進(jìn)程拋出panic錯(cuò)誤，內(nèi)核就掛起了。根據(jù)分析定位的原因，我又通過(guò)修改內(nèi)核代碼去構(gòu)造時(shí)間溢出的條件，就是通過(guò)內(nèi)核模塊去修改系統(tǒng)調(diào)用時(shí)間的計(jì)數(shù)值，修改是成功了，可惜內(nèi)核也直接死掉了。所以直接修改內(nèi)核代碼來(lái)重現(xiàn)也失敗了。

　　后面也陸續(xù)咨詢了很多公司外面熟悉內(nèi)核的技術(shù)人員，他們根據(jù)我們提供的信息業(yè)給出了自己的分析，但是也沒(méi)有很好的重現(xiàn)方法和確切的定位錯(cuò)誤原因，而且不同的人給出的結(jié)論差異也比較大。

　　所以第一個(gè)階段連續(xù)堅(jiān)持跟蹤這個(gè)問(wèn)題2-3周的時(shí)間也沒(méi)有一個(gè)確切的結(jié)果。

　　3.第二階段

　　新的一年開始了，第一天又開始準(zhǔn)備跟蹤這個(gè)問(wèn)題了。一開始也制定了簡(jiǎn)單的計(jì)劃，我對(duì)自己的計(jì)劃就是每天5-8點(diǎn)分析定位內(nèi)核問(wèn)題，當(dāng)然也順便學(xué)習(xí)內(nèi)核相關(guān)知識(shí)。

　　這一次一開始自己便換了一個(gè)角度去思考問(wèn)題，去年是基于單臺(tái)服務(wù)器去分析內(nèi)核日志錯(cuò)誤信息，已經(jīng)沒(méi)有什么好的方式了。所以準(zhǔn)備同時(shí)分析所有出錯(cuò)服務(wù)器的日志（幸好以前找運(yùn)維要了所有出錯(cuò)服務(wù)器的內(nèi)核日志并且保存下來(lái)了，不然怎么死的都不知道），找出他們的共同點(diǎn)。首先他們的共同點(diǎn)就是出現(xiàn)了trace子系統(tǒng)打印的警告信息“Delta way too big！…。。”的信息，但是根據(jù)相關(guān)信息，這個(gè)是不會(huì)導(dǎo)致linux系統(tǒng)掛起的。而且確實(shí)我們線上的服務(wù)器并不是全部都ssh不上去，不過(guò)還是在RedHat官方網(wǎng)站找到類似的bug（url：

　　https： //access.redhat.com/knowledge/solutions/70051），并且給出了解決方案。bug信息和解決方案如下：

　　why kernel is throwing “Delta way too big” out with

　　WARNING： at kernel trace ring_buffer，c:1988 rb_reserve_next_event+0x2ce/0×370 messages

　　0 Issue kernel is throwing ”Delta way too big” out with kernel oops on server

　　Environment（環(huán)境）

　　•Red Hat Enterprise Linux 6 service pack 1

　　Resolution（解決方案）

　　The warning ”Delta way too big” warning might appear on a system with unstable shed clock right after the system is resumed and tracingwas enabled during the suspend.

　　Since it’s not realy bug， and the unstable sched clock is working fast and reliable otherwise， We suggested to keep using the sched clock in any case and just to make note in the warning itself.or disables tracing by #echo 0 》 /sys/kernel/debug/tracing/tracing_on

　　Root Cause（根本原因） this case was ftrace involved ftrace due to teh call to ftrace_raw_event_power_end （debugfs is mounted and ftrace loaded in this case）， they are to do with problems calculating a time stamp for a ring buffer entry.

　　Message comes from here and appears to be indicating problems with time stability.

　　1966 static int

　　1967 rb_add_time_stamp（struct ring_buffer_per_cpu *cpu_buffer，

　　1968 u64 *ts， u64 *delta）

　　1969 {

　　1970 struct ring_buffer_event *event;

　　1971 static int once;

　　1972 int ret;

　　1973

　　1974 if （unlikely（*delta 》 （1ULL 《《 59） && ！once++）） {

　　1975 int local_clock_stable = 1;

　　1976 #ifdef CONFIG_HAVE_UNSTABLE_SCHED_CLOCK

　　1977 local_clock_stable = sched_clock_stable;

　　1978 #endif

　　1979 printk（KERN_WARNING ”Delta way too big！ %llu”

　　1980 “ ts=%llu write stamp = %llu\n%s”，

　　1981 （unsigned long long）*delta，

　　1982 （unsigned long long）*ts，

　　1983 （unsigned long long）cpu_buffer-》write_stamp，

　　1984 local_clock_stable ？ ”“ ：

　　1985 “If you just came from a suspend/resume，\n”

　　1986 “please switch to the trace global clock：\n”

　　1987 ” echo global 》 /sys/kernel/debug/tracing/trace_clock\n”）;

　　1988 WARN_ON（1）;

　　This called from rb_reserve_next_event（） here.

　　2122 /*

　　2123 * Only the first commit can update the timestamp.

　　2124 * Yes there is a race here. If an interrupt comes in

　　2125 * just after the conditional and it traces too， then it

　　2126 * will also check the deltas. More than one timestamp may

　　2127 * also be made. But only the entry that did the actual

　　2128 * commit will be something other than zero.

　　2129 */

　　2130 if （likely（cpu_buffer-》tail_page == cpu_buffer-》commit_page &&

　　2131 rb_page_write（cpu_buffer-》tail_page） ==

　　2132 rb_commit_index（cpu_buffer））） {

　　2133 u64 diff;

　　2134

　　2135 diff = ts - cpu_buffer-》write_stamp;

　　2136

　　2137 /* make sure this diff is calculated here */

　　2138 barrier（）;

　　2139

　　2140 /* Did the write stamp get updated already？ */

　　2141if （unlikely（ts 《 cpu_buffer-》write_stamp））

　　2142 goto get_event;

　　2143

　　2144 delta = diff;

　　2145 if （unlikely（test_time_stamp（delta））） {

　　2146

　　2147 commit = rb_add_time_stamp（cpu_buffer， &ts， &delta）; 《—- HERE

　　This has to do with time stamping for ring buffer entries.

　　通過(guò)上面的信息可以看出，其實(shí)和我去年分析的代碼和方式一模一樣，只是判斷原因方面我不敢確定，畢竟重現(xiàn)不了，只能是推測(cè)。