Alter Log中VKTM時間drift漂移現象

Alter Log中VKTM時間drift漂移現象

時間是包括資料庫系統在內的諸多資訊系統基礎件的重要因素。對於運行在作業系統OS之上的中介軟體組件而言，擷取到一個準確、連續和一致的時間非常重要，特別是多節點的環境下。如果沒有一個統一的時間管理機制，其上的cluster組件工作是及其困難的。

本篇主要介紹Oracle vktm時間後台進程警示的Bug問題。

1、從11g VKTM進程談起

對Oracle資料庫，避免對於作業系統層面時間的調用，維持一個統一穩定的時間體系一直是發展方向。在11g中，一個獨立的後台進程vktm被引入到執行個體體系下。

VKTM進程全稱為“Virtual Keeper of Time Process”，用於給資料庫運行和間隔運算計量提供出一個統一的時間服務。官方解釋是：

VKTM acts as a time publisher for an Oracle instance. VKTM publishes two sets of time: a wall clock time using a seconds interval and a higher resolution time (which is not wall clock time) for interval measurements. The VKTM timer service centralizes time tracking and offloads multiple timer calls from other clients.

在11g之前的版本中，如果資料庫執行個體（包括ASM和RAC Instance）需要目前時間的時候，都叫用作業系統層面的時間擷取函數（例如：gettimeofday()）。進入11g之後，這個動作就由統一的VKTM負責完成，並且在進程內部保留時間過程。其他進程如果需要時間，都通過這個進程間接獲得。專門的時間後台進程的出現，最直接的效果就是減少了同作業系統核心的互動，提高了效能。

2、Time Drift問題

在一次日誌巡檢中，筆者發現alert log中存在如下的警示資訊：

Tue Dec 22 21:56:26 2015

Warning: VKTM detected a time drift.

Time drifts can result in an unexpected behavior such as time-outs. Please check trace file for more details.

Tue Dec 22 23:02:44 2015

Warning: VKTM detected a time drift.

Time drifts can result in an unexpected behavior such as time-outs. Please check trace file for more details.

alert log是我們探索資料庫運行問題最直接的途徑和方法。從11g開始，一些預測、診斷性的資訊，也都通過alert log進行輸出，期望實現資料庫故障問題預先診斷。

從日誌資訊看，資料庫在兩個時間點經曆了兩次VKTM進程的Time Drift現象。Drift是漂移、浮動的含義。VKTM作為時間維護後台進程，在兩個時間點中似乎發生了快速的前移和後退。

根據日誌中資訊時間資訊，我們尋找定位故障發生時的trace檔案。

[oracle@vLIFE-URE-PRD-DB-PRIMARY trace]$ ls -l | grep vktm

（篇幅原因，有省略……）

-rw-r-----. 1 oracle oinstall    90 Dec 21 14:48 UREPRD_vktm_22700.trm

-rw-r-----. 1 oracle oinstall  1846 Dec 22 23:02 UREPRD_vktm_23138.trc

-rw-r-----. 1 oracle oinstall    128 Dec 22 23:02 UREPRD_vktm_23138.trm

對應的Trace檔案資訊如下：

kstmmainvktm: failed in setting elevated priority

Verify: SETUID is set on ORADISM and restart the instance

highres_enabled

VKTM running at (100ms) precision 

kstmrmtickcntkeeper: param _dbrm_quantum will not be effective

*** 2015-12-21 16:15:27.883

[Start] HighResTick = 1450685727883070

kstmrmtickcnt = 0, ksudbrmseccnt[0] = 1450685727

kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (16898372)usec at (1450792586464465) whereas (1000000) is allowed

*** 2015-12-22 21:56:27.439

kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (18000000)usec at (1450792587) whereas (5000000) is allowed

kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1112648)usec at (1450796564826494) whereas (1000000) is allowed

在alert結果中，我們看到兩次漂移drift的現象。資訊中，我們看到一個單位usec，摺合0.000001秒鐘。那麼，兩個提示的意思就比較明確了：VKTM進程向前分別跳躍了18秒和1.1秒。規定的跳躍時間是1秒鐘。

那麼，下一個問題是，問題是怎麼產生的？我們是否需要介入處理？alter log中一些警示資訊是基於資料庫診斷規則，警告的內容涵蓋記憶體、安全、儲存等多個方面。並不是每一種資訊都需要進行處理，很多資訊內容都是基於最佳Oracle工作實踐的一種建議。

在MOS中，筆者定位到了一篇針對alert log中出現Time Drift提示錯誤的文章，名稱為：Time Drift Detected. Please Check VKTM Trace File for More Details，文章編號：ID 1347586.1。

在文章中，Oracle認為這個錯誤在11.2.0.2到11.2.0.3之間會不斷地出現，已經在11.2.0.4版本中被修複。Bug編號為：11837095 "TIME DRIFT DETECTED" APPEARS INTERMITTENTLY IN ALERT LOG, THO' EVENT 10795 SET。

如果需要對該Bug進行單獨修複，需要進行補丁patch 11837095操作。之後通過設定等待事件10795來進行控制。

alter system set event="10795 trace name context forever, level 2" scope=spfile;

這種錯誤的潛在影響，MOS文章中的解釋如下：

Impact of the error:

The time drifts usually occurring less than 1sec and 5 sec for forward and backward respectively are permissible and OK.

If the traces are emitting time drifts of amount beyond these ranges, then it needs to be analyzed.

Most of the times, during high loads, there would be issues with underlying OS due to virtual memory, network time protocol improper configuration etc.

In general VKTM process need to be scheduled in every 10ms, if due to above reasons this is not happening we see the time drifts and to certain level (mentioned above) are permissible.

Eventually, this probably would cause the resource manager to take improper decisions and can lead to a hang in worst case.

VKTM process trace file can be found under bdump, However in this case the trace file doesn't contain useful information, Which makes the message ambiguous.

大部分情況下，由於系統高負載或者記憶體調度配置有問題，VKTM的每10ms作業會有問題，可能會出現1-5秒的Drift漂移。如果這種現象出現很頻繁，就需要整體考慮作業系統和資料庫配置問題。VKTM出現漂移，可能會影響到resource manager的工作情況。

3、結論

VKTM是Oracle 11g中新引入的一個後台進程。我們在面對alert log中出現的各種奇怪問題的時候，最好主動諮詢一下官方MOS，看看是否有相似的方案解決。小問題儘早解決，才能保證系統不出現大故障。