用Lgwr Worker 的例子介紹 Strace 分析 Oracle 數據庫行為的方法
可觀測性能力是IT運維的強有力的支撐。日志告警、指標是兩種在運維中很常用的可觀測性指標。而對于數據庫這樣復雜的IT組件來說,有時候僅僅依靠日志和指標還是不夠的。
跟蹤是解決數據庫復雜問題的十分常用和有效的方法。今年的openGauss 開發者大會上,華為的黃凱耀分享的案例就是使用了eBPF進行跟蹤,最終精準定位了一個比較復雜的性能問題。在跟蹤方面,國產數據庫與Oracle等傳統商用國數據庫還有這很大的技術差距。做好跟蹤并不容易,讓運維人員或者售后服務人員能夠很方便的跟蹤數據庫的某種運行行為可以幫助提升運維,加快BUG定位。
Oracle提供了十分強大的分析功能,特別是EVENT設置。我剛剛開始學習Oracle不久,就學會了使用event 10046去跟蹤SQL語句的執行。這對于我剛剛開始接觸Oracle這個黑匣子的說話幫助巨大。在缺乏必要的資料,甚至連一個METALINK賬號都沒有的時期,學習Oracle數據字典的基本原理,以及數據庫啟動時的主要動作等,都是通過10046 trace文件完成的。后來也經常使用10046/10053等事件分析,來解決用戶的SQL語句性能問題。后來我學習一些Oracle新特性的說話,還是經常會使用event做一些trace。
前兩天研究了一下Oracle的LGWR worker新機制,我后來也問了一些客戶,在一些系統規模不是很大的場景,好像客戶都沒有感受到這個新的變化。也有寫負載較大的用戶遇到了LOG FILE SYNC延時過高的問題,后來通過將LGWR改為原來的寫模式解決了問題。于是我昨天寫了一篇相關的文章,猜測了一下Oracle實現這個功能的原理。當天下午和一個朋友聊起這個事情,他希望我能夠進一步確認一下我的猜測是否靠譜。在網上能夠找到的資料極少,于是我只能再次使用起5、6年沒用過的跟蹤大法來做一個分析。
分析Oracle數據庫的后臺進程功能有一種十分常用的方法,這個是我從Poder大師那邊學來的。結合10046和LINUX的strace,可以比較清晰的分析Oracle后臺進程的一些行為。因為10046中會輸出某個會話執行過的SQL語句,產生過的各種等待事件,利用這個TRACE上的時間戳,結合strace對于調用堆棧的跟蹤,就很容易進行問題定位了。這個方法歸納起來很簡單:首先對需要跟蹤的后臺進程設置8級的10046 TRACE,然后開啟壓測腳本,同事啟用strace對調用堆棧進行跟蹤就可以了。我們來看看這個完整的過程。
首先我們找到要跟蹤的進程,我們準備跟蹤lgwr和lg00。然后分別針對這兩個進程設置10046 trace。
在兩個窗口中分別通過oradebug設置好之后。我們就可以啟用一個壓測工具slob去產生一些寫負載了。為了減少跟蹤的日志量,我們把slob設置為1個進程,并且只啟動一個并發。
啟動好壓測負載后,我們就可以分別在兩個窗口中對lgwr/lg00進行strace跟蹤了:
對于strace不太熟悉的朋友我可以解釋一下,-T -tt是在每個調用前顯示時間戳,-s是對于每個調用的數據,最多顯示512字節。-p -o我就不解釋了,估計地球人都明白。跑上幾十秒鐘后,我們就可以停止跟蹤了,因為大部分的行為都十分類似,沒必要跑太久。
我們先來看看lg00的strace跟蹤信息,因為我加上了-s參數,因此在trace里可以看到所有寫入lg00 trace文件的數據的前面512字節。因此我不需要去查看orcl1_lg00_15626.trc文件了。
上面這段trace的開始是lg00完成了一個日志寫入的工作,進入Idle等待狀態。隨后就收到了寫任務,開始寫入REDO文件,大家注意看因為使用了異步IO,因此lg00通過io_submit來提交IO。我們往下看,可以發現lg00隨后發生了ASM IO for non-blocking poll等待,這是因為向ASM發出了IO。然后lg00產生了我們熟悉的log file parallel write等待。到收到io_getevents為止,異步寫完成。于是lg00記錄了log file parallel write等待完成。
從日志中我們可以梳理出一個大致的脈絡。可以看出在Oracle等待事件的統計時長與實際情況并不完全一致。事實上數據庫也沒必要十分精確的統計等待時長,只要是一個大致的就足夠了。只要誤差都是差不多的,對于實際分析來說并沒有太大的問題。
我們再來看看lgwr的相關時段的跟蹤信息。為了方便查看,我梳理了一個表格,從中可以看出整個過程。
我們先來看lgwr,收到寫請求后,找到了一個空閑的worker,然后發出寫任務。同時發現所有的worker都處于忙的狀態。此時正好沒有寫任務,于是發出一個本地IPC消息,等待ipc消息回復。
而lg00收到寫任務后,首先異步提交了IO,然后產生了一系列預期的寫日志的等待。完成后先通知lgwr,然后再給等待著發通知。這個算法是比較合理的,由lg00直接發消息給log file sync等待的會話,而不是通過lgwr,這樣會有更高的效率。和我由lgwr發消息,lgwr worker無阻塞寫的想法不一致。二者可能在面對不同場景時各有優勢,到底哪種更好也不太好判斷,也不在我們今天討論的范圍內。今天我們重點要介紹的是跟蹤數據庫后臺進程行為的方法。