We've seen something similar to this, but perhaps a bit different.
On Wed, 2 Feb 2011, Carsten Winkler (HZB) wrote:
> Epics time goes crazy if I run softIoc with Epics base 3.14.12 (with all
> official patches) in a virtual machine.
Our problem occurred with EPICS 3.14.11.
> I use following configuration:
> Hypervisor: kvm
> Architecture: x86_64
> Guest: Windows XP (32-bit)
Our system administrator tells me that Windows XP doesn't support time
paravirtualisation, and that in this case you can expect your time to be
all over the place. Do you know what your host system was?
Our problem was a bit stranger, with both RHEL5 host and guest system, and
quite difficult to reproduce. After some searching I've found a couple of
Red Hat bug reports that seem related:
https://bugzilla.redhat.com/show_bug.cgi?id=531268
https://bugzilla.redhat.com/show_bug.cgi?id=521517
However, we were running with the linked advisory updates already applied.
I've been digging around trying to find out more about this issue, and it
seems rather complicated. Here are some more related links:
http://serverfault.com/questions/132197/best-practice-for-system-clock-sync-on-kvm-host
http://www.vmware.com/pdf/vmware_timekeeping.pdf
though, of course, vmware is nothing directly to do with the issue.
> All works fine if I use a single core VM.
That's *very* interesting to learn, didn't know that. I'll find out how
many cores our VM was using.
We found that running generalTimeReport on the offending IOC would report
astronomical numbers of timing errors, and that the time as seen by the
system would glitch forward and back by an hour or more. I didn't succeed
in demonstrating the problem with a smaller example, so your tiny example
below is rather nice.
I haven't tried reproducing the problem for a couple of months or so ...
would be interested to hear from anyone else with time keeping problems on
virtual servers, but for the time being my IOCs are running on real
hardware.
> But if I use two or more CPU cores Epics time does several funny actions.
> * I also get events with a new value but previous time stamp.
> * Timestamps are wrong and in the future.
> * I get the message: "currentTime::getCurrentTime(): 7623636.000000sec time
> discontinuity detected".
>
> I've logged a test variable, which increments value every second.
>
> -------------------------------------------------------------------------
>
> record(ai, "demoHost:aiExample")
> {
> field(DESC, "Analog input")
> field(INP, "demoHost:calcExample.VAL NPP NNS")
> field(EGU, "Counts")
> field(HOPR, "10")
> field(LOPR, "0")
> field(HIHI, "8")
> field(HIGH, "6")
> field(LOW, "4")
> field(LOLO, "2")
> field(HHSV, "MAJOR")
> field(HSV, "MINOR")
> field(LSV, "MINOR")
> field(LLSV, "MAJOR")
> }
> record(calc, "demoHost:calcExample")
> {
> field(DESC, "Counter")
> field(SCAN, "1 second")
> field(FLNK, "demoHost:aiExample")
> field(CALC, "(A<B)?(A+C):D")
> field(INPA, "demoHost:calcExample.VAL NPP NNS")
> field(INPB, "9")
> field(INPC, "1")
> field(INPD, "0")
> field(EGU, "Counts")
> field(HOPR, "10")
> field(LOPR, "0")
> field(HIHI, "8")
> field(HIGH, "6")
> field(LOW, "4")
> field(LOLO, "2")
> field(HHSV, "MAJOR")
> field(HSV, "MINOR")
> field(LSV, "MINOR")
> field(LLSV, "MAJOR")
> }
>
> -------------------------------------------------------------------------
>
> This is the log of "camonitor.exe":
> ###################################
>
> One second = 1 minute?!!!
> =========================
> ...
> demoHost:aiExample 2011-02-02 11:04:02.893304 5
> demoHost:aiExample 2011-02-02 11:04:55.757528 6 HIGH MINOR
> demoHost:aiExample 2011-02-02 11:05:35.900993 7 HIGH MINOR
> demoHost:aiExample 2011-02-02 11:05:44.292108 8 HIHI MAJOR
> demoHost:aiExample 2011-02-02 11:06:10.091333 9 HIHI MAJOR
> demoHost:aiExample 2011-02-02 11:07:11.216996 0 LOLO MAJOR
> demoHost:aiExample 2011-02-02 11:08:16.242185 1 LOLO MAJOR
> demoHost:aiExample 2011-02-02 11:09:00.773516 2 LOLO MAJOR
> demoHost:aiExample 2011-02-02 11:09:43.136728 3 LOW MINOR
> demoHost:aiExample 2011-02-02 11:10:25.476922 4 LOW MINOR
> demoHost:aiExample 2011-02-02 11:11:32.704872 5
> ...
>
> Allways the same time stamp?!!!
> ===============================
> ...
> demoHost:aiExample 2011-02-02 12:58:24.858648 5
> demoHost:aiExample 2011-02-02 12:58:24.858648 6 HIGH MINOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 7 HIGH MINOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 8 HIHI MAJOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 9 HIHI MAJOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 0 LOLO MAJOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 1 LOLO MAJOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 2 LOLO MAJOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 3 LOW MINOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 4 LOW MINOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 5
> demoHost:aiExample 2011-02-02 12:58:24.858648 6 HIGH MINOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 7 HIGH MINOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 8 HIHI MAJOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 9 HIHI MAJOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 0 LOLO MAJOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 1 LOLO MAJOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 2 LOLO MAJOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 3 LOW MINOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 4 LOW MINOR
> demoHost:aiExample 2011-02-02 12:58:24.858648 5
> ...
>
> The error message
> =================
> ...
> demoHost:aiExample 2011-02-02 13:09:15.978653 0 LOLO MAJOR
> demoHost:aiExample 2011-02-02 13:09:15.978653 1 LOLO MAJOR
> demoHost:aiExample 2011-02-02 13:09:15.978653 2 LOLO MAJOR
> currentTime::getCurrentTime(): 7623636.000000 sec time discontinuity detected
> currentTime::getCurrentTime(): 250144975.000000 sec time discontinuity
> detected
> demoHost:aiExample 2011-02-02 13:09:15.978653 3 LOW MINOR
> currentTime::getCurrentTime(): 249700665.000000 sec time discontinuity
> detected
> demoHost:aiExample 2011-02-02 13:09:15.978653 4 LOW MINOR
> demoHost:aiExample 2011-02-02 13:09:15.978653 5
> demoHost:aiExample 2011-02-02 13:09:15.978653 6 HIGH MINOR
> currentTime::getCurrentTime(): 241047173.000000 sec time discontinuity
> detected
> ...
- References:
- time discontinuity detected Carsten Winkler (HZB)
- Navigate by Date:
- Prev:
RE: calc doesn't appear to be working with MEDM for string expressions(Win32 Extension Version 1.40) Mark Rivers
- Next:
USB-scopes, anyone? Benjamin Franksen
- Index:
1994
1995
1996
1997
1998
1999
2000
2001
2002
2003
2004
2005
2006
2007
2008
2009
2010
<2011>
2012
2013
2014
2015
2016
2017
2018
2019
2020
2021
2022
2023
2024
- Navigate by Thread:
- Prev:
time discontinuity detected Carsten Winkler (HZB)
- Next:
Re: time discontinuity detected Andrew Johnson
- Index:
1994
1995
1996
1997
1998
1999
2000
2001
2002
2003
2004
2005
2006
2007
2008
2009
2010
<2011>
2012
2013
2014
2015
2016
2017
2018
2019
2020
2021
2022
2023
2024
|
·
Home
·
News
·
About
·
Base
·
Modules
·
Extensions
·
Distributions
·
Download
·