1 Reply Latest reply: Feb 25, 2013 8:25 AM by Nadeem M RSS

    11g XE in vmware time drifts - how to avoid

    Alain
      Hi, using 11gxe in a VMware virtual machine on Linux 2.6.32-5-amd64 #1 SMP Sun Sep 23 10:07:46 UTC 2012 x86_64 GNU/Linux.

      alert_log shows:
      Mon Feb 25 10:16:53 2013
      VKTM detected a time drift. Please check trace file for more details.


      Trace file is:
      Trace file /u01/app/oracle/diag/rdbms/xe/XE/trace/XE_vktm_1063.trc
      Oracle Database 11g Express Edition Release 11.2.0.2.0 - 64bit Beta
      ORACLE_HOME = /u01/app/oracle/product/11.2.0/xe
      System name: Linux
      Node name: pc
      Release: 2.6.32-5-amd64
      Version: #1 SMP Sun Sep 23 10:07:46 UTC 2012
      Machine: x86_64
      VM name: VMWare Version: 6
      Instance name: XE
      Redo thread mounted by this instance: 0 <none>
      Oracle process number: 4
      Unix process pid: 1063, image: oracle@pc (VKTM)


      *** 2013-02-06 13:40:19.067
      *** CLIENT ID:() 2013-02-06 13:40:19.067
      *** SERVICE NAME:() 2013-02-06 13:40:19.067
      *** MODULE NAME:() 2013-02-06 13:40:19.067
      *** ACTION NAME:() 2013-02-06 13:40:19.067

      ksesethighpri: (ksb.c:4235) Failed to elevate VKTM's priority from 0 to 1
      Error Info: Category(-2), Opname(skgdism_create), Loc(sp.c:1564), ErrMsg(Error 0) Dism(300399922)
      *** SESSION ID:(4.1) 2013-02-06 13:40:19.071
      *** SERVICE NAME:() 2013-02-06 13:40:19.071

      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 dbrmquantum will not be effective

      *** 2013-02-06 13:40:19.072
      [Start] HighResTick = 1360154419071992
      kstmrmtickcnt = 0, ksudbrmseccnt[0] = 1360154419
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1029093)usec at (1360231288029393) whereas (1000000) is allowed
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1044505)usec at (1360239182388521) whereas (1000000) is allowed

      *** 2013-02-07 13:25:01.436
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1134446)usec at (1360239901436504) whereas (1000000) is allowed
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1036080)usec at (1360240414393089) whereas (1000000) is allowed
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1008348)usec at (1360241301114015) whereas (1000000) is allowed
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1587918)usec at (1360246161921393) whereas (1000000) is allowed
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1165047)usec at (1360246692534792) whereas (1000000) is allowed
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1072386)usec at (1360247565678837) whereas (1000000) is allowed

      *** 2013-02-07 15:34:32.527
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1188521)usec at (1360247672527445) whereas (1000000) is allowed
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1128629)usec at (1360248314383796) whereas (1000000) is allowed
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1009564)usec at (1360252847259327) whereas (1000000) is allowed
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (6000000)usec at (1360254610) whereas (5000000) is allowed

      *** 2013-02-07 17:30:34.222
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1056907)usec at (1360254634222048) whereas (1000000) is allowed
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (8000000)usec at (1360254637) whereas (5000000) is allowed

      *** 2013-02-07 17:30:38.751
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1007374)usec at (1360254638751325) whereas (1000000) is allowed

      *** 2013-02-07 17:30:49.818
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1021696)usec at (1360254649818004) whereas (1000000) is allowed
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (6000000)usec at (1360254652) whereas (5000000) is allowed

      *** 2013-02-07 17:31:04.052
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (7000000)usec at (1360254664) whereas (5000000) is allowed

      *** 2013-02-07 17:31:20.927
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (6000000)usec at (1360254680) whereas (5000000) is allowed

      *** 2013-02-07 17:31:29.464
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1013055)usec at (1360254689464430) whereas (1000000) is allowed

      *** 2013-02-07 17:31:37.578
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (6000000)usec at (1360254697) whereas (5000000) is allowed

      *** 2013-02-07 17:31:45.257
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (6000000)usec at (1360254705) whereas (5000000) is allowed

      *** 2013-02-07 17:31:59.949
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (6000000)usec at (1360254719) whereas (5000000) is allowed

      *** 2013-02-07 17:32:05.545
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (6000000)usec at (1360254725) whereas (5000000) is allowed

      *** 2013-02-07 17:32:11.042
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (6000000)usec at (1360254731) whereas (5000000) is allowed

      *** 2013-02-07 17:32:14.386
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1040654)usec at (1360254734386739) whereas (1000000) is allowed

      *** 2013-02-07 17:32:22.182
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (6000000)usec at (1360254742) whereas (5000000) is allowed

      *** 2013-02-07 17:32:24.059
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1080088)usec at (1360254744059735) whereas (1000000) is allowed
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (7000000)usec at (1360254749) whereas (5000000) is allowed

      *** 2013-02-07 17:32:35.629
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (6000000)usec at (1360254755) whereas (5000000) is allowed

      *** 2013-02-07 17:32:41.189
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (6000000)usec at (1360254761) whereas (5000000) is allowed

      *** 2013-02-07 17:32:45.215
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1080867)usec at (1360254765215263) whereas (1000000) is allowed
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (7000000)usec at (1360254768) whereas (5000000) is allowed
      ...
      *** 2013-02-25 08:39:05.474
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (6872514)usec at (1361777945474112) whereas (1000000) is allowed
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (9000000)usec at (1361777945) whereas (5000000) is allowed

      *** 2013-02-25 08:40:32.616
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1548842)usec at (1361778032084300) whereas (1000000) is allowed
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (7000000)usec at (1361778036) whereas (5000000) is allowed

      *** 2013-02-25 08:40:36.825
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (4740971)usec at (1361778036825271) whereas (1000000) is allowed

      *** 2013-02-25 08:45:09.235
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (2191152)usec at (1361778308860685) whereas (1000000) is allowed
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1836107)usec at (1361779014940497) whereas (1000000) is allowed

      *** 2013-02-25 08:56:56.015
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1074637)usec at (1361779016015134) whereas (1000000) is allowed

      *** 2013-02-25 08:57:13.240
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1763875)usec at (1361779033240748) whereas (1000000) is allowed

      *** 2013-02-25 08:57:20.241
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1340569)usec at (1361779040241925) whereas (1000000) is allowed

      *** 2013-02-25 08:57:26.031
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1175168)usec at (1361779046031736) whereas (1000000) is allowed

      *** 2013-02-25 08:57:39.118
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (11124612)usec at (1361779059118209) whereas (1000000) is allowed
      kstmchkdrift (kstmrmtickcntkeeper:lowres): Time jumped forward by (12000000)usec at (1361779059) whereas (5000000) is allowed

      *** 2013-02-25 08:57:43.078
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1081496)usec at (1361779063078282) whereas (1000000) is allowed

      *** 2013-02-25 08:58:07.400
      kstmchkdrift (kstmrmtickcntkeeper:highres): Time jumped forward by (1169814)usec at (1361779087400183) whereas (1000000) is allowed

      *** 2013-02-25 09:02:23.217
      [End] HighResTick = 1361779343217604
      kstmrmtickcnt = 15720671, ksudbrmseccnt[1572067] = 1361779343


      finally oracle takes 100% cpu time and we have to restart it. Any hint to avoid this? (e.g. allowing more by 1000000 )?