在solaris10上安装了oracle 11.2.0.3的数据库，手工建库以后，发现告警日志里面有个非常有规律的报警信息，每隔76分钟报一次，报警信息如下：
Tue Aug 0503:05:18 2014 Time drift detected. Please check VKTM trace file for more details. Tue Aug 05 03:08:48 2014 Starting background process SMCO Tue Aug 05 03:08:48 2014 SMCO started with pid=24, OS id=2446 Tue Aug 05 03:14:35 2014 Stopping background process CJQ0 Tue Aug 0504:12:34 2014 Time drift detected. Please check VKTM trace file for more details. Tue Aug 0505:28:47 2014 Time drift detected. Please check VKTM trace file for more details. Tue Aug 0506:44:59 2014 Time drift detected. Please check VKTM trace file for more details. Tue Aug 0508:01:26 2014 Time drift detected. Please check VKTM trace file for more details. Tue Aug 05 09:17:33 2014 Time drift detected. Please check VKTM trace file for more details.
告警日志提示看trace文件，trace文件内容如下：
[[email protected]:/u01/app/oracle/diag/rdbms/anny/anny/trace]$ cat anny_vktm_2378.trc Trace file /u01/app/oracle/diag/rdbms/anny/anny/trace/anny_vktm_2378.trc Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production With the Partitioning, OLAP, Data Mining and Real Application Testing options ORACLE_HOME = /u01/app/oracle/product/11.2.0/dbhome_1 System name: SunOS Node name: solaris186 Release: 5.10 Version: Generic_142910-17 Machine: i86pc Instance name: anny Redo thread mounted by this instance: 0 <none> Oracle process number: 4 Unix process pid: 2378, image: [email protected] (VKTM) *** 2014-08-05 02:58:43.036 *** SESSION ID:(4.1) 2014-08-05 02:58:43.036 *** CLIENT ID:() 2014-08-05 02:58:43.036 *** SERVICE NAME:() 2014-08-05 02:58:43.036 *** MODULE NAME:() 2014-08-05 02:58:43.036 *** ACTION NAME:() 2014-08-05 02:58:43.036 kstmmainvktm: succeeded in setting elevated priority highres_enabled *** 2014-08-05 02:58:43.036 VKTM running at (10)millisec precision with DBRM quantum (100)ms [Start] HighResTick = 59404806322 kstmrmtickcnt = 0 : ksudbrmseccnt[0] = 1407178723 *** 2014-08-05 03:05:18.798 kstmchkdrift (kstmhighrestimecntkeeper:highres): Time jumped forward by (1297157)usec at (59800568177) whereas (1000000) is allowed kstmchkdrift (kstmhighrestimecntkeeper:lowres): Time stalled at 1407180887 *** 2014-08-05 03:34:48.908 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Stall, backward drift ended at 1407180888 drift: 1 *** 2014-08-05 03:35:18.823 kstmchkdrift (kstmhighrestimecntkeeper:highres): Time jumped forward by (1366639)usec at (61602594030) whereas (1000000) is allowed kstmchkdrift (kstmhighrestimecntkeeper:lowres): Time stalled at 1407183154 *** 2014-08-05 04:12:35.900 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Stall, backward drift ended at 1407183155 drift: 1 *** 2014-08-05 04:12:51.999 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Time stalled at 1407183171 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Stall, backward drift ended at 1407183172 drift: 1 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Time stalled at 1407185440 *** 2014-08-05 04:50:41.947 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Stall, backward drift ended at 1407185441 drift: 1 *** 2014-08-05 04:50:58.972 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Time stalled at 1407185458 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Stall, backward drift ended at 1407185459 drift: 1 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Time stalled at 1407187727 *** 2014-08-05 05:28:48.883 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Stall, backward drift ended at 1407187728 drift: 1 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Time stalled at 1407187744 *** 2014-08-05 05:29:05.931 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Stall, backward drift ended at 1407187745 drift: 1 *** 2014-08-05 05:43:59.944 kstmchkdrift (kstmhighrestimecntkeeper:highres): Time jumped forward by (1252499)usec at (69329714522) whereas (1000000) is allowed kstmchkdrift (kstmhighrestimecntkeeper:highres): Time jumped forward by (1419573)usec at (70537192617) whereas (1000000) is allowed *** 2014-08-05 06:06:53.993 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Time stalled at 1407190013 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Stall, backward drift ended at 1407190014 drift: 1 *** 2014-08-05 06:07:11.988 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Time stalled at 1407190031 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Stall, backward drift ended at 1407190032 drift: 1 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Time stalled at 1407192299 *** 2014-08-05 06:45:00.927 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Stall, backward drift ended at 1407192300 drift: 1 *** 2014-08-05 06:45:17.960 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Time stalled at 1407192317 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Stall, backward drift ended at 1407192318 drift: 1 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Time stalled at 1407194588 *** 2014-08-05 07:23:09.922 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Stall, backward drift ended at 1407194589 drift: 1 *** 2014-08-05 07:23:26.979 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Time stalled at 1407194606 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Stall, backward drift ended at 1407194607 drift: 1 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Time stalled at 1407196886 *** 2014-08-05 08:01:27.919 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Stall, backward drift ended at 1407196887 drift: 1 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Time stalled at 1407199171 *** 2014-08-05 08:39:32.932 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Stall, backward drift ended at 1407199172 drift: 1 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Time stalled at 1407201453 *** 2014-08-05 09:17:34.920 kstmchkdrift (kstmhighrestimecntkeeper:lowres): Stall, backward drift ended at 1407201454 drift: 1
从trace文件没有得到有用的信息，但这个信息不影响数据库的使用，查看官方文档说这是一个bug，网上说是因为vktm这个进程每隔一段时间会与ntp server进行对时，但我机器的ntp 服务是没有打开的。
[[email protected]:/]# svcs -a ntp svcs: -a ignored when used with arguments. STATE STIME FMRI disabled 10:30:01 svc:/network/ntp:default
在Oracle Database
11g中，VKTM是一个新增的后台进程。这个进程的含义是：
VKTM (virtual keeper of time) is responsible for providing a wall-clock time (updated every second) and reference-time counter (updated every 20 ms and available only when running at elevated priority).
也就是说，这个进程用于提供一个数据库的时钟，每秒更新；或者作为参考时间计数器，这种方式每20毫秒更新一次，仅在高优先级时可用。
通过VKTM进程，数据库可以降低和操作系统的交互，Kamus的解释是：在11g之前所有的Oracle数据库后台或者前台进程如果需要获得当前时间信息，就需要调用操作系统的gettimeofday()函数或者说是相类似的函数。而VKTM进程就是专门用来获得时间信息然后将信息存放在SGA中供其它进程使用，这样其它进程当需要时间信息的时候，只要到SGA的某个内存位置去获得就好，而不用频繁调用gettimeofday()函数。毫无疑问，这样效率会更高。
在RAC测试中，Oracle
1.1.0.6版本LMSx进程获取时间信息时，可以从VKTM进程中获益大概70%的速度提升，而11.1.0.7将会更高。同时，因为gettimeofday()函数也引发了很多bug，所以无论是RAC还是NORAC库，都将从VKTM进程中获益。
最后结论：
猜测这个bug在所有平台上都有可能触发，由于我机器的ntp服务没有启动，所以vktm进程与ntp服务进行对时，触发了这个bug。如果你机器上有ntp 服务，那么时间差异大的话也会触发这个bug。
Time drift detected
时间： 2024-11-05 21:31:07