分析trace日志的一個(gè)思路

1、昨天還在跟y抱怨寫書的人會在書里大量帖日志來充字?jǐn)?shù)坑讀者撈錢的事，不過剛才有一庫掛了，開始查閱日志。在分析一個(gè)trace日志時(shí)，翻閱了下eygle的一個(gè)很經(jīng)典的分析思路的文章，整理了下給大家。文章的重點(diǎn)不是導(dǎo)致報(bào)錯(cuò)的原因跟解決的辦法，而是尋找問題的思路與手段，eygle也是最擅長這樣剝絲抽繭般地尋找問題。這才是最寶貴的，畢竟一旦知道真正的原因了，問題就立刻有辦法迎刃而解了，而最難的是如何去發(fā)現(xiàn)問題的根源。在acle數(shù)據(jù)庫的運(yùn)行過程中，可

2、能會因?yàn)橐恍┊惓Ｓ龅綌?shù)據(jù)庫掛起失去響應(yīng)的狀況，在這種狀況下，我們可以通過對系統(tǒng)狀態(tài)進(jìn)行轉(zhuǎn)儲，獲得跟蹤文件進(jìn)行數(shù)據(jù)庫問題分析；很多時(shí)候數(shù)據(jù)庫也會自動(dòng)轉(zhuǎn)儲出現(xiàn)問題的進(jìn)程或系統(tǒng)信息；這些轉(zhuǎn)儲信息成為我們分析故障、排查問題的重要依據(jù)。1.1狀態(tài)轉(zhuǎn)儲的常用命令當(dāng)數(shù)據(jù)庫出現(xiàn)一些掛起狀態(tài)時(shí)，往往會嚴(yán)重影響到數(shù)據(jù)庫使用，進(jìn)程級的問題影響范圍較小，而系統(tǒng)級的問題則會影響全局。在出現(xiàn)數(shù)據(jù)庫系統(tǒng)或進(jìn)程失去響應(yīng)時(shí)，如果SQLPlus工具仍然可以連接，可能視圖查

3、詢沒有相應(yīng)，但是可以通過adebug工具來進(jìn)行進(jìn)程及系統(tǒng)狀態(tài)信息的轉(zhuǎn)儲，從而可以進(jìn)行Hang分析。DUMP進(jìn)程狀態(tài)可以使用：altersessionsseteventsimmediatetracenameprocessstatelevel；或者使用：adebugsetmypidadebugulimitadebugdumpprocessstate當(dāng)診斷數(shù)據(jù)庫掛起時(shí)，可以使用DUMP命令轉(zhuǎn)儲整個(gè)系統(tǒng)狀態(tài)：altersessionssetev

4、entsimmediatetracenamesystemstatelevel；或：adebugsetmypidadebugulimitadebugdumpsystemstate如果為了獲取全面一點(diǎn)的信息，可以使用Level10。SQLadebugsetmypidSQLadebugunlimitSQLadebugdumpsystemstate10另外如果系統(tǒng)掛起，無法用SQLPlus連接，從acle10g開始，可以使用sqlpluspre

5、lim選項(xiàng)強(qiáng)制登錄，然后即可進(jìn)行系統(tǒng)狀態(tài)信息轉(zhuǎn)儲：sqlplusprelimassysdbaadebugsetmypidadebugunlimitadebugdumpsystemstate101.2WAITEDTOOLONGFAROWCACHEENQUEUELOCK!案例在一次客戶現(xiàn)場培訓(xùn)中，客戶提出一個(gè)系統(tǒng)正遇到問題，請求我協(xié)助診斷解決，理論聯(lián)系實(shí)踐，這是我在培訓(xùn)中極力主張的，我們的案例式培訓(xùn)業(yè)正好遇到了實(shí)踐現(xiàn)場。問題是這樣的：PRO

6、CESS29:SO:6c1006740type:2owner:0flag:INIT0x00(process)aclepid=29callscurtop:6c10974306c1096bf0flag:(0)interr:0callerr:0sesserr:0txnerr0(postinfo)lastpostreceived:10904lastpostreceivedlocation:kslpsrlastprocesstopostme:6c

7、100280016lastpostsent:0024lastpostsentlocation:ksasndlastprocesspostedbyme:6c100280016(latchinfo)wait_event=0bits=0ProcessGroup:DEFAULTpseudoproc:4f818c298OSinfo:user:acleterm:UNKNOWNospid:8371OSDpidinfo:Unixprocesspid:8

8、371image:acleEDW@SF2900進(jìn)一步的向下檢查可以找到SO對象6c10508e8，這里顯示該進(jìn)程確實(shí)由客戶端的SQLPlus發(fā)起，并且客戶端的主機(jī)名稱及進(jìn)程的OSPID都記錄在案：SO:6c10508e8type:4owner:6c1006740flag:INIT0x00(session)sid:120trans:6c285ea98creat:6c1006740flag:(100041)USRBSYDID:0001001

9、D001BC795shttermDID:0000000000000000txnbranch:0oct:2prv:0sql:4f528d510psql:491cbe3e8user:56CACIOSinfo:user:Administratterm:HOST03ospid:37692:38132machine:program:sqlplus.exeapplicationname:SQLPlushashvalue=3669949024接下來的

10、信息顯示，進(jìn)程一直在等待，等待事件為ksdxexeotherwait：lastwaitfksdxexeotherwaitblockingsess=0x0seq=36112wait_time=5secondssincewaitstarted=3=0=0=0DumpingSessionWaitHistyfksdxexeotherwaitcount=1wait_time=5=0=0=0fksdxexeotherwaitcount=1wait_

11、time=5=0=0=0fksdxexeotherwaitcount=1wait_time=3=0=0=0fksdxexeotherwaitcount=1wait_time=5=0=0=0fksdxexeotherwaitcount=1wait_time=4=0=0=0fksdxexeotherwaitcount=1wait_time=3=0=0=0fksdxexeotherwaitcount=1wait_time=4=0=0=0fks