以Lgwr Worker為例,基於Strace 分析 Oracle 資料庫行為的方法

大雄45發表於2022-09-18
導讀 從日誌中我們可以梳理出一個大致的脈絡。可以看出在Oracle等待事件的統計時長與實際情況並不完全一致。事實上資料庫也沒必要十分精確的統計等待時長,只要是一個大致的就足夠了。只要誤差都是差不多的,對於實際分析來說並沒有太大的問題。

可觀測效能力是IT運維的強有力的支撐。日誌告警、指標是兩種在運維中很常用的可觀測性指標。而對於資料庫這樣複雜的IT元件來說,有時候僅僅依靠日誌和指標還是不夠的。

以Lgwr Worker為例,基於Strace 分析 Oracle 資料庫行為的方法以Lgwr Worker為例,基於Strace 分析 Oracle 資料庫行為的方法

跟蹤是解決資料庫複雜問題的十分常用和有效的方法。今年的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和 的strace,可以比較清晰的分析Oracle後臺程式的一些行為。因為10046中會輸出某個會話執行過的SQL語句,產生過的各種等待事件,利用這個TRACE上的時間戳,結合strace對於呼叫堆疊的跟蹤,就很容易進行問題定位了。這個方法歸納起來很簡單:首先對需要跟蹤的後臺程式設定8級的10046 TRACE,然後開啟壓測 ,同事啟用strace對呼叫堆疊進行跟蹤就可以了。我們來看看這個完整的過程。

以Lgwr Worker為例,基於Strace 分析 Oracle 資料庫行為的方法以Lgwr Worker為例,基於Strace 分析 Oracle 資料庫行為的方法

首先我們找到要跟蹤的程式,我們準備跟蹤lgwr和lg00。然後分別針對這兩個程式設定10046 trace。

以Lgwr Worker為例,基於Strace 分析 Oracle 資料庫行為的方法以Lgwr Worker為例,基於Strace 分析 Oracle 資料庫行為的方法

在兩個視窗中分別透過oradebug設定好之後。我們就可以啟用一個壓測工具slob去產生一些寫負載了。為了減少跟蹤的日誌量,我們把slob設定為1個程式,並且只啟動一個併發。

以Lgwr Worker為例,基於Strace 分析 Oracle 資料庫行為的方法以Lgwr Worker為例,基於Strace 分析 Oracle 資料庫行為的方法

啟動好壓測負載後,我們就可以分別在兩個視窗中對lgwr/lg00進行strace跟蹤了:

以Lgwr Worker為例,基於Strace 分析 Oracle 資料庫行為的方法以Lgwr Worker為例,基於Strace 分析 Oracle 資料庫行為的方法

對於strace不太熟悉的朋友我可以解釋一下,-T -tt是在每個呼叫前顯示時間戳,-s是對於每個呼叫的資料,最多顯示512位元組。-p -o我就不解釋了,估計地球人都明白。跑上幾十秒鐘後,我們就可以停止跟蹤了,因為大部分的行為都十分類似,沒必要跑太久。

以Lgwr Worker為例,基於Strace 分析 Oracle 資料庫行為的方法以Lgwr Worker為例,基於Strace 分析 Oracle 資料庫行為的方法

我們先來看看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 Worker為例,基於Strace 分析 Oracle 資料庫行為的方法以Lgwr Worker為例,基於Strace 分析 Oracle 資料庫行為的方法

我們再來看看lgwr的相關時段的跟蹤資訊。為了方便檢視,我梳理了一個表格,從中可以看出整個過程。

以Lgwr Worker為例,基於Strace 分析 Oracle 資料庫行為的方法以Lgwr Worker為例,基於Strace 分析 Oracle 資料庫行為的方法

我們先來看lgwr,收到寫請求後,找到了一個空閒的worker,然後發出寫任務。同時發現所有的worker都處於忙的狀態。此時正好沒有寫任務,於是發出一個本地IPC訊息,等待ipc訊息回覆。

而lg00收到寫任務後,首先非同步提交了IO,然後產生了一系列預期的寫日誌的等待。完成後先通知lgwr,然後再給等待著發通知。這個演算法是比較合理的,由lg00直接發訊息給log file sync等待的會話,而不是透過lgwr,這樣會有更高的效率。和我由lgwr發訊息,lgwr worker無阻塞寫的想法不一致。二者可能在面對不同場景時各有優勢,到底哪種更好也不太好判斷,也不在我們今天討論的範圍內。今天我們重點要介紹的是跟蹤資料庫後臺程式行為的方法。

原文來自:


來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/69955379/viewspace-2915153/,如需轉載,請註明出處,否則將追究法律責任。

相關文章