[[398590]]

本文轉載自微信公眾號「數(shù)據(jù)和云」，作者王鑫。轉載本文請聯(lián)系數(shù)據(jù)和云公眾號。

 一、問題描述

近日在某客戶現(xiàn)場進行巡檢，發(fā)現(xiàn)有一個系統(tǒng)在進行sqlplus / as sysdba登錄的時候特別緩慢。多次測試，最長時間可以達到近10s才能成功登錄。此時，對主機的CPU、內存、IO以及網(wǎng)絡等參數(shù)進行查看，發(fā)現(xiàn)使用率均不高，遠遠沒有達到瓶頸，且在登錄之前和登錄之后，所有操作均非常順滑，沒有任何卡頓。因此，判斷該系統(tǒng)就是在sqlplus登錄的時候才可能出現(xiàn)卡頓。

由于客戶的業(yè)務并未反饋使用有問題，所以當時僅將該問題記錄到日常錯誤處理日志中。但是過了幾天后，突然客戶的業(yè)務使用人員說，他們的某功能經(jīng)常出現(xiàn)連接超時問題。這個時候，我就很肯定業(yè)務也受到了sqlplus登錄緩慢所帶來的影響。于是專門翻出這個問題進行進一步的分析和排查。

二、問題分析過程

在此之前，其實也遇到過很多次sqlplus登錄緩慢的問題，而造成該問題的原因就是客戶使用了DNS進行IP解析。sqlplus在登錄的時候會解析DNS，而在解析這一步耗費的時間較長，從而影響了sqlplus登錄過程所消耗的時間。

所以，本次就先入為主，查看是否在服務器環(huán)境中存在DNS的配置：

cat /etc/resolv.conf 
 
# Generated by NetworkManager 

可以發(fā)現(xiàn)，主機上并沒有DNS配置，所以造成sqlplus登錄緩慢的常見原因也不是這個造成的。

那么，我們則需要進行進一步的原因排查。

首先，我們需要了解到，針對于Oracle數(shù)據(jù)庫的異常排查有一些很有用的方式，比如oradebug、event分析、hanganalyze、strace等等，只有我們選對了異常排查方式，才能夠事半功倍。

而對于sqlplus登錄緩慢的問題，由于起初不知道是因為數(shù)據(jù)庫原因造成，還是因為命令調用原因造成，所以我們可以考慮選擇hanganalyze或者strace的方式進行排查。

針對本次異常，首先對數(shù)據(jù)庫進行了hanganalyze分析，但是分析出的結果并未顯示出有阻塞鏈。所以，問題應該處在sqlplus命令調用原因。此時，我們就可以用strace的方式進行分析了：

strace -T -tt -o /tmp/strace_sqlplus_local.txt sqlplus / as sysdba

通過以上命令，可以生成一個sqlplus命令在執(zhí)行期間對Linux做了那些調用的文件。通過該文件，我們則可以看到在哪個過程調用比較慢。

通過對生成的文件進行查看分析，發(fā)現(xiàn)在以下這一步驟調用時間出現(xiàn)異常：

可以發(fā)現(xiàn)此時在該步驟調用的時間有7秒多。

所以，此時我們能確定到問題點在什么地方。但是是什么原因造成的這個地方調用緩慢呢?我們可以看到其中有NTP0的字樣，所以當時也懷疑是否與NTP服務有關。

進一步，我對NTP的相關服務進行檢查，發(fā)現(xiàn)在該服務器上并沒有任何NTP的配置，而且NTP服務也都沒有開啟。

分析到這里，也是有點迷惑了，這一步到底是在做什么?為什么會導致這么慢?此時我也有點無從下手了，還好有公司二線專家，請教了二線專家后，讓我在strace中在加入-Fr參數(shù)，更近一步的去fork調用的子進程。

strace -T -tt -Fr -o /tmp/strace_sqlplus_local.txt sqlplus / as sysdba 

可以看到，在這里有一段mmap()函數(shù)的調用耗費的時間比較長，基本上在4s左右(這里可能和上面的時間不匹配，主要是在分析的時候生成了多次的原因)。

而經(jīng)過查詢，發(fā)現(xiàn)mmap函數(shù)主要是Linux下內存映射到文件的一種方法(具體的該函數(shù)的內容和功能，我沒有詳細研究)，因此可以猜測，sqlplus登錄緩慢的問題，可能出現(xiàn)在內存映射上。

于是再進一步，對Oracle的內存分配以及相關的內存參數(shù)進行查看，最終發(fā)現(xiàn)了一個參數(shù)：pre_page_sga，該參數(shù)在當前環(huán)境中設置的為true，而該參數(shù)默認為false。

三、問題原因定位

pre_page_sga這個參數(shù)有什么作用呢?從官網(wǎng)和其他blog中，查到這個參數(shù)的作用如下：

在Oracle實例啟動時，只會在物理內存中載入sga的各個內存的最小的大小(以粒度為單位)，而剩余的sga只會在虛擬內存中分配。只有當進程touch到相應的page時，才會置換到物理內存中。當參數(shù)設置為TRUE時，不僅在實例啟動時，需要touch所有的SGA頁，并且由于每個Oracle進程都會訪問SGA區(qū)，所以每當一個新進程啟動時(在Dedicated Server方式中，每個會話都會啟動一個Oracle進程)，都會touch一遍該進程需要訪問的所有頁。

通過以上描述，我們可以知道如果將改參數(shù)設置為true的時候，每次我們進行sqlplus登錄的時候，實際上都會生成一個Oracle進程，而此時改進程會touch一遍所有需要訪問的內存頁。當需要訪問的內存頁很大的時候，可能就會產(chǎn)生緩慢的情況。

四、問題解決

后來我也建議客戶將該參數(shù)改為false，在客戶修改、重啟后進行測試，發(fā)現(xiàn)sqlplus登錄緩慢問題解決。再次通過strace生成sqlplus的跟蹤文件可以發(fā)現(xiàn)，此時在NTP0的地方，效率變得非常高了。

五、總結

本次問題是一個常見問題，但不是一個常見原因導致。一個簡單的sqlplus登錄緩慢問題，造成原因可能很多，從跟蹤日志中來看包括DNS、內存、adump日志過多、讀取glogin.sql等等。本篇文章的目的，其實更多的是提供了一種遇到類似問題的分析思路，供大家參考。

關于作者

王鑫，云和恩墨西區(qū)交付團隊技術顧問，從事Oracle DBA工作7年左右，服務客戶包含電力、軍工、政府、金融等，擁有Oracle OCP、OCM，PGCA、PGCE多項認證，擅長Oracle數(shù)據(jù)庫遷移、異常診斷。