菜鳥(niǎo)求助：xen的bug時(shí)鐘頻率

sansitaotao

硬件 thinkpad t43

軟件 RHEL5U2 xen內(nèi)核  

啟動(dòng)xen domain0.引導(dǎo)過(guò)程就開(kāi)始報(bào)如下錯(cuò)誤：
warning Timer ISR/0 ;Time went backwards: delta=-9101039 cpu_delta=10898961 shadow=89150287265250 off=9333682407 processed8 0: 89159610048608 1: ...登錄root
該錯(cuò)誤定時(shí)發(fā)作，出現(xiàn)在屏幕上，并記入messege日志

查閱資料
google搜索 Timer ISR/0 time went backwards
沒(méi)查到可用的解決方案
倒是在baidu找到幾篇中文的研究，但看不明白，沒(méi)有明示解決方案

檢查后發(fā)現(xiàn)
系統(tǒng)時(shí)鐘和bios時(shí)鐘是同步的

請(qǐng)高人指點(diǎn)

sansitaotao

t43的硬件是cpu迅馳1.75還是半虛擬化支持的

而我同樣操作安裝臺(tái)式機(jī)賽揚(yáng)2.6cpu就不報(bào)這個(gè)錯(cuò)

因此我也猜測(cè)是t43筆記本的省電模式作怪，對(duì)硬件一竅不通，誰(shuí)能幫忙解答




再貼一篇研究的文章：
一個(gè)有趣的和時(shí)鐘相關(guān)的bug

前幾天解決了一個(gè)bug（6563730），感覺(jué)整個(gè)解決的過(guò)程很有趣，覺(jué)得有記錄下來(lái)的必要。

這個(gè)bug的現(xiàn)象很奇怪，某些硬件（主要是Sun Fire X2100 M2/X2200 M2）上運(yùn)行的Solaris的dom0（簡(jiǎn)稱為：i86xpv平臺(tái)）上的時(shí)間跑的比普通Solaris（直接運(yùn)行在硬件上的Solaris - i86pc平臺(tái)）快。經(jīng)過(guò)測(cè)試發(fā)現(xiàn)，普通的Solaris運(yùn)行60秒，Solaris dom0的時(shí)間過(guò)了70秒左右。但是，運(yùn)行在同一個(gè)機(jī)器上的Linux dom0并沒(méi)有發(fā)現(xiàn)類似的現(xiàn)象。

一開(kāi)始，大家對(duì)這個(gè)bug都有些發(fā)懵，覺(jué)得有點(diǎn)丈二和尚的感覺(jué)。最開(kāi)始研究這個(gè)bug的工程師經(jīng)過(guò)一段時(shí)間的調(diào)試，發(fā)現(xiàn)這個(gè)bug和USB的EHCI控制器的驅(qū)動(dòng)有關(guān)。而USB驅(qū)動(dòng)的開(kāi)發(fā)小組就在中國(guó)，和我在同一個(gè)辦公樓里，交流方便。于是，這個(gè)bug就被轉(zhuǎn)到了我手中（我們小組只有我一個(gè)人在中國(guó)，其他人都在美國(guó)或英國(guó)）。

之所以說(shuō)有可能是EHCI驅(qū)動(dòng)程序的問(wèn)題是因?yàn)槲覀儼l(fā)現(xiàn)時(shí)鐘運(yùn)行速度突變是發(fā)生在EHCI驅(qū)動(dòng)加載的時(shí)候。具體來(lái)說(shuō)，是當(dāng)EHCI驅(qū)動(dòng)在初始化的時(shí)候?qū)⒁粋�(gè)EHCI設(shè)備寄存器的某一個(gè)比特置位時(shí)，時(shí)鐘運(yùn)行速度突然變快了�？雌饋�(lái)確實(shí)像是EHCI驅(qū)動(dòng)的問(wèn)題。但是，我的USB知識(shí)有限，只好請(qǐng)USB組的工程師幫忙了。經(jīng)過(guò)了大約兩周的忙活（主要是那位被我抓住干活的USB組的工程師在忙活，謝謝�。�，我們覺(jué)得似乎從USB這邊是無(wú)法解決這個(gè)奇怪的問(wèn)題了。他都快要把Solaris的EHCI驅(qū)動(dòng)改成和Linux一樣了（暈�。�，但是還是看不到一絲效果。無(wú)法理解為什么Linux的dom0沒(méi)有這個(gè)問(wèn)題。。。

于是我只好把bug拿回來(lái)仔細(xì)看看。我對(duì)于Solaris和Xen里面時(shí)間的處理沒(méi)有什么概念，只好從頭看起了。我們重現(xiàn)這個(gè)bug的方式是同時(shí)在Solaris dom0和普通Solaris里面運(yùn)行‘date’命令，并重復(fù)幾次。這樣就可以發(fā)現(xiàn)時(shí)間運(yùn)行速度的差異了。于是，先看看date命令吧。用truss發(fā)現(xiàn)date通過(guò)系統(tǒng)調(diào)用time來(lái)取得系統(tǒng)當(dāng)前的時(shí)間。我找到time系統(tǒng)調(diào)用在內(nèi)核中的處理函數(shù)（usr/src/uts/common/os/sysent.c）是gtime()。然后一直跟著代碼gtime()->gethrestime_sec()->gethrestime()->gethrestimef()->pc_gethrestime()->gethrtime()->gethrtimef()->dtrace_xpv_gethrtime()。這里需要注意的是，在i86pc上，gethrtime()調(diào)用dtrace_gethrtime()，而在i86xpv平臺(tái)調(diào)用的是dtrace_xpv_gethrtime()。

其實(shí)，這個(gè)地方是我們把Solaris移植到Xen上需要進(jìn)行的平臺(tái)相關(guān)的改動(dòng)之一：讀取高精度（以納秒為單位）時(shí)間的方式變化了。在i86pc上，事情相對(duì)簡(jiǎn)單些。在dtrace_gethrtime()中，我們讀取到CPU的本地TSC計(jì)數(shù)器的當(dāng)前值tsc，找到自從上次tsc_last更新后（tsc_tick()每秒鐘更新一次tsc_last）的變化量delta（ = tsc – tsc_last）并將其轉(zhuǎn)換成為以納秒為單位的時(shí)間（TSC計(jì)數(shù)和納秒的轉(zhuǎn)換關(guān)系在CPU啟動(dòng)的時(shí)候就確定下來(lái)了，存放在nsec_scale中）。于是，在i86pc平臺(tái)上，Solaris利用BSP的本地APIC（Local APIC）定時(shí)器定時(shí)產(chǎn)生時(shí)鐘中斷，每秒鐘讀取TSC計(jì)數(shù)一次（并寫(xiě)入tsc_last），來(lái)跟蹤時(shí)間至秒的精度。并且在兩次tsc_last更新期間，通過(guò)讀取TSC計(jì)數(shù)的差值來(lái)跟蹤時(shí)間至納秒的精度。

Solaris i86pc對(duì)時(shí)間的處理是基于一個(gè)假設(shè)：TSC計(jì)數(shù)器的頻率是恒定不變的。這個(gè)假設(shè)對(duì)于在物理機(jī)器上運(yùn)行的Solaris是十分合適的（CPU的運(yùn)行頻率總不會(huì)一會(huì)兒快一會(huì)兒慢吧）。但是對(duì)于虛擬機(jī)來(lái)說(shuō)就不一定成立了。因?yàn)樘摂M機(jī)運(yùn)行的真實(shí)運(yùn)行硬件平臺(tái)是不確定的。OS在運(yùn)行過(guò)程中隨時(shí)有可能會(huì)被遷移（migrate）到另外一個(gè)硬件平臺(tái)上去運(yùn)行。那么在該OS的生命周期之內(nèi)CPU的運(yùn)行頻率就無(wú)法保持不變了。因此，TSC計(jì)數(shù)和時(shí)間的對(duì)應(yīng)關(guān)系就有可能在虛擬機(jī)完全不知情的情況下發(fā)生變化。因此，時(shí)間相關(guān)的信息需要Xen來(lái)直接告訴虛擬機(jī)。

Xen定義了一個(gè)時(shí)間相關(guān)的數(shù)據(jù)結(jié)構(gòu)（每個(gè)虛擬CPU都包含一個(gè)）：vcpu_time_info_t（usr/src/uts/common/xen/public/xen.h）。這個(gè)數(shù)據(jù)結(jié)構(gòu)中的內(nèi)容是由Xen來(lái)更新（當(dāng)虛擬CPU被調(diào)度運(yùn)行的時(shí)候更新），OS只是從中讀取需要的信息來(lái)跟蹤時(shí)間的流逝。其中system_time是OS到目前為止運(yùn)行的時(shí)間（單位：秒），tsc_timestamp是當(dāng)Xen更新system_time時(shí)候的TSC計(jì)數(shù)，tsc_to_system_mul是一個(gè)因數(shù)，用來(lái)表示TSC計(jì)數(shù)和時(shí)間的對(duì)應(yīng)關(guān)系。于是通過(guò)類似dtrace_gethrtime()的算法，dtrace_xpv_gethrtime()也就可以知道當(dāng)前的時(shí)間了。最重要的一點(diǎn)是在讀取這個(gè)數(shù)據(jù)結(jié)構(gòu)的時(shí)候必須保證數(shù)據(jù)的一致性（包括所有數(shù)據(jù)結(jié)構(gòu)的各個(gè)成員和當(dāng)時(shí)的TSC計(jì)數(shù)值）。顯然我們無(wú)法用一個(gè)原子操作來(lái)保證一次讀取到所有的數(shù)據(jù)。因此，Xen在這個(gè)數(shù)據(jù)結(jié)構(gòu)中增加了一個(gè)成員：version。Xen在更新這個(gè)數(shù)據(jù)結(jié)構(gòu)的時(shí)候會(huì)改變version的值。因此，只有當(dāng)我們開(kāi)始讀取這些數(shù)據(jù)和讀取完畢的時(shí)候version沒(méi)有發(fā)生過(guò)變化，我們才認(rèn)為數(shù)據(jù)的讀取是可靠的。

代碼讀到這里，似乎沒(méi)法從Solaris里面找到問(wèn)題了（dtrace_xpv_gethrtime()的實(shí)現(xiàn)很簡(jiǎn)單，也沒(méi)有什么錯(cuò)誤）。沒(méi)辦法，只好接著往底下挖了，看看是不是Xen把時(shí)間搞錯(cuò)了。。。這里寫(xiě)起來(lái)好像是挺簡(jiǎn)單的決定，但是越走下去心越虛。因?yàn)長(zhǎng)inux dom0沒(méi)有出現(xiàn)類似的問(wèn)題這個(gè)事實(shí)總是在腦子里面揮之不去。大家都使用的同一套Xen的代碼呀，這樣看來(lái)，問(wèn)題應(yīng)該是出現(xiàn)在Solaris內(nèi)部了。進(jìn)一步挖掘Xen的代碼，是不是在走彎路呢？

萬(wàn)般無(wú)奈，只好接著調(diào)試一下Xen的代碼了，彎路就彎路吧，總比沒(méi)路可走強(qiáng)。經(jīng)過(guò)一些實(shí)驗(yàn)，我發(fā)現(xiàn)tsc_to_system_mul這個(gè)值在EHCI驅(qū)動(dòng)加載前后發(fā)生了較大的變化。加載之前，這個(gè)數(shù)字雖然也不是恒定的，但是變化比較�。ㄊ�六進(jìn)制表示的時(shí)候，高5位都不發(fā)生變動(dòng)）。但是在加載后，變動(dòng)就比較明顯了（十六進(jìn)制表示的時(shí)候，最高位都會(huì)發(fā)生變化）。這里面肯定有問(wèn)題��！因?yàn)門(mén)SC計(jì)數(shù)和時(shí)間的對(duì)應(yīng)關(guān)系不會(huì)有如此大的變動(dòng)的。否則，Solaris i86pc的時(shí)間計(jì)算就肯定出錯(cuò)了。在Solaris i86pc中，TSC計(jì)數(shù)和時(shí)間的對(duì)應(yīng)關(guān)系是CPU啟動(dòng)的時(shí)候進(jìn)行校準(zhǔn)的，之后不再改動(dòng)了。從這可以看出來(lái)Solaris對(duì)于TSC的頻率的穩(wěn)定是深信不疑的。Xen的代碼對(duì)于時(shí)間的處理似乎比Solaris更加復(fù)雜。它好像并不像Solaris一樣對(duì)TSC計(jì)數(shù)器的頻率那么相信。Xen使用一個(gè)在主板上的外部時(shí)鐘源每隔一段時(shí)間校準(zhǔn)（調(diào)用local_time_calibration()）一次TSC計(jì)數(shù)和時(shí)間的關(guān)系。它的校準(zhǔn)算法很簡(jiǎn)單。首先從外部時(shí)鐘源讀取時(shí)鐘的計(jì)數(shù)變化（自從上次校準(zhǔn)時(shí)的計(jì)數(shù)變化），再讀取TSC計(jì)數(shù)的變化。將兩者進(jìn)行比較后就得到對(duì)應(yīng)關(guān)系。嗯，看上去沒(méi)有什么問(wèn)題。那么，唯一可能影響對(duì)應(yīng)關(guān)系的計(jì)算結(jié)果的因素應(yīng)該是外部的時(shí)鐘源自身的計(jì)數(shù)頻率出問(wèn)題了。如果真是這樣，那么用一個(gè)本身計(jì)數(shù)頻率就不準(zhǔn)確的時(shí)鐘來(lái)校準(zhǔn)TSC的計(jì)數(shù)頻率，得到的只能是錯(cuò)誤的結(jié)果。

看來(lái)需要研究一下Xen所相信的那個(gè)時(shí)鐘源是不是有問(wèn)題了。主板上的外部時(shí)鐘源倒是有好幾種，例如PIT時(shí)鐘和HPET時(shí)鐘。Xen在這個(gè)出問(wèn)題的硬件平臺(tái)上所使用的是PIT時(shí)鐘（HPET看來(lái)還是太先進(jìn)了，目前還不是每個(gè)主板都提供的）。PIT時(shí)鐘硬件上提供三個(gè)計(jì)數(shù)器：計(jì)數(shù)器0（PIT0）是用來(lái)產(chǎn)生整個(gè)系統(tǒng)的心跳時(shí)鐘中斷的（IRQ0），計(jì)數(shù)器1（PIT1）是用來(lái)給DRAM提供動(dòng)態(tài)數(shù)據(jù)刷新的時(shí)鐘中斷的，而計(jì)數(shù)器2（PIT2）則被Xen用來(lái)作為校準(zhǔn)用的時(shí)鐘源。TSC的計(jì)數(shù)頻率是由CPU的運(yùn)行頻率，似乎沒(méi)有理由出問(wèn)題。而PIT的1.193MHz的時(shí)鐘頻率更是業(yè)界幾十年的標(biāo)準(zhǔn)，已經(jīng)在主板硬件上做死了，誰(shuí)也沒(méi)法改，怎么可能忽快忽慢呢？！看來(lái)要搞清楚到底是TSC的計(jì)數(shù)頻率出了問(wèn)題還是PIT2的頻率出了問(wèn)題還真是挺讓人頭疼的一件事情�，F(xiàn)在需要找一個(gè)經(jīng)過(guò)驗(yàn)證，絕對(duì)沒(méi)有問(wèn)題的第三個(gè)時(shí)鐘來(lái)校準(zhǔn)PIT2了。還好，主板上帶的RTC似乎沒(méi)有受到任何干擾，一直在正常的運(yùn)行。這是因?yàn)楫?dāng)機(jī)器上運(yùn)行Solaris dom0一段時(shí)間后，立即重起進(jìn)入BIOS，發(fā)現(xiàn)RTC時(shí)鐘并沒(méi)有變快。好，終于有一個(gè)可以讓人相信的時(shí)鐘源了！盡管RTC的分辨率低了些，但是作為校準(zhǔn)足夠用了。于是，我先在IRQ0的中斷處理函數(shù)中讀取RTC的值來(lái)校準(zhǔn)PIT0，發(fā)現(xiàn)PIT0一直都工作在1.193MHz的頻率上，沒(méi)有發(fā)生過(guò)任何問(wèn)題。于是，我再在IRQ0的處理函數(shù)中讀取PIT2的計(jì)數(shù)值。結(jié)果終于出來(lái)了，當(dāng)EHCI驅(qū)動(dòng)加載時(shí)修改那個(gè)寄存器的瞬間，PIT2的計(jì)數(shù)頻率發(fā)生了突變（狐貍尾巴開(kāi)始顯現(xiàn)了，哈）！

但是問(wèn)題開(kāi)始變得越來(lái)越神秘了。搜索了Xen的整個(gè)代碼樹(shù)，自從PIT2在Xen啟動(dòng)的時(shí)候被初始化好了以后，沒(méi)有任何代碼再碰過(guò)它。那是什么原因使得PIT2的計(jì)數(shù)頻率發(fā)生了突變呢？Solaris運(yùn)行時(shí)，它的任何一個(gè)應(yīng)用程序根本不會(huì)去修改PIT2的配置。Solaris的內(nèi)核也從來(lái)沒(méi)有使用過(guò)PIT時(shí)鐘。Xen的代碼在初始化后也沒(méi)有再修改過(guò)PIT2的設(shè)置。好像是有一個(gè)神秘的力量，當(dāng)EHCI初始化一個(gè)寄存器的時(shí)候修改了PIT2的配置，導(dǎo)致PIT2的計(jì)數(shù)頻率發(fā)生了改變。

如果不是Solaris的應(yīng)用程序，也不是Solaris的內(nèi)核，也不是Xen，那么當(dāng)時(shí)有可能進(jìn)入犯罪現(xiàn)場(chǎng)的就只有BIOS的代碼了。可惜，BIOS的代碼不對(duì)我開(kāi)放，只好和做主板的公司聯(lián)系一下了。于是我們開(kāi)始了近一個(gè)月的馬拉松式的交流。雙方的知識(shí)背景相差較大：他們完全不知道Xen，也從來(lái)沒(méi)有使用過(guò)Solaris。我也完全看不明白他們發(fā)過(guò)來(lái)的PIT硬件設(shè)計(jì)圖。交流的初期還真叫一個(gè)亂。在兩個(gè)公司領(lǐng)導(dǎo)的大力支持下，在雙方工程師彼此之間的相互信任和配合下，我們終于成功的在他們公司內(nèi)部的一臺(tái)機(jī)器上重現(xiàn)了問(wèn)題。萬(wàn)里長(zhǎng)征邁出了艱難的第一步。之后，我們就找到了共同語(yǔ)言，事情的進(jìn)展就比較的順利了。功夫不負(fù)有心人，最終，我們發(fā)現(xiàn)了罪魁禍?zhǔn)�。。�?br />
原來(lái)，當(dāng)EHCI驅(qū)動(dòng)初始化那個(gè)寄存器的時(shí)候引發(fā)了一個(gè)SMI中斷，系統(tǒng)進(jìn)入了SMM模式，BIOS的代碼開(kāi)始運(yùn)行。BIOS的代碼要讓機(jī)器的揚(yáng)聲器發(fā)出“嗶”的一聲（真是沒(méi)事瞎添亂），因?yàn)锽IOS偵測(cè)到USB設(shè)備狀態(tài)發(fā)生了變化。而PIT2的一個(gè)重要的職責(zé)就是負(fù)責(zé)給揚(yáng)聲器提供一定頻率的方波，來(lái)發(fā)出所需的聲音，所以BIOS改動(dòng)了PIT2的設(shè)置來(lái)產(chǎn)生所需要的頻率。。。

后來(lái)經(jīng)過(guò)一通google才知道，Linux在啟動(dòng)系統(tǒng)的時(shí)候就禁掉了SMM。。。

至此，真相大白于天下了！

sansitaotao

我寫(xiě)一下自己的解決方案

在grub.conf中，
kernel xen.img 后面添加：（我內(nèi)存是1g）

dom0_mem=1000000 cdb=com1H com1=115200,8n1 sched=sedf conswitch=x hpet_force=1

將時(shí)鐘改為hpet了，雖然非常懵懂，但效果不錯(cuò)：
原來(lái)每分鐘報(bào)錯(cuò)20條以上，修改以后每分鐘報(bào)錯(cuò)不到一條，基本在3-4分鐘來(lái)一條報(bào)錯(cuò)
暫時(shí)先這樣吧，實(shí)在查不到好的資料

q1208c

http://bugzilla.xensource.com/bugzilla/show_bug.cgi?id=195

看看這個(gè). 也許有幫助.