This discussion is archived
1 Reply Latest reply: Feb 25, 2013 6:25 AM by 881508 RSS

11g XE in vmware time drifts - how to avoid

Alain Newbie
Currently Being Moderated
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 )?

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points