分析trace日志的一個思路

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

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

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

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

5、lim選項強制登錄，然后即可進行系統(tǒng)狀態(tài)信息轉(zhuǎn)儲：sqlplusprelimassysdbaadebugsetmypidadebugunlimitadebugdumpsystemstate101.2WAITEDTOOLONGFAROWCACHEENQUEUELOCK!案例在一次客戶現(xiàn)場培訓(xùn)中，客戶提出一個系統(tǒng)正遇到問題，請求我協(xié)助診斷解決，理論聯(lián)系實踐，這是我在培訓(xùn)中極力主張的，我們的案例式培訓(xùn)業(yè)正好遇到了實踐現(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進一步的向下檢查可以找到SO對象6c10508e8，這里顯示該進程確實由客戶端的SQLPlus發(fā)起，并且客戶端的主機名稱及進程的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、信息顯示，進程一直在等待，等待事件為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