The incorrect way to compute the roll-over in WIN32 osdTime.cpp

[Alex Chen]

EPICS Base 3.14.9

File: \src\libCom\osi\os\WIN32\osdTime.cpp
May occurs in other files.

Problem:
There are a lot of places in this file to handle the roll-over case. e.g. at line 379, ' offset = ( MAXLONGLONG - this->lastPerfCounter ) + ( curPerfCounter.QuadPart + MAXLONGLONG );', I don't understand why we add the second 'MAXLONGLONG'. IMHO, it should be ' offset = ( MAXLONGLONG - this->lastPerfCounter ) + curPerfCounter.QuadPart;'

[Andrew Johnson (anj)]

Jeff,

This code does look wrong, maybe the second MAXLONGLONG was supposed to be MINLONGLONG instead? Even in that case though I suspect there's an off-by-1 error in the result:

        if ( curPerfCounter.QuadPart >= this->lastPerfCounter ) {
            offset = curPerfCounter.QuadPart - this->lastPerfCounter;
        }
        else {
            //
            // must have been a timer roll-over event
            //
            // It takes 9.223372036855e+18/perf_freq sec to roll over this
            // counter. This is currently about 245118 years using the perf
            // counter freq value on my system (1193182). Nevertheless, I
            // have code for this situation because the performance
            // counter resolution will more than likely improve over time.
            //
            offset = ( MAXLONGLONG - this->lastPerfCounter )
                                + ( curPerfCounter.QuadPart + MAXLONGLONG );
        }

[Jeff Hill (johill-lanl)]

Agree that it should be

            offset = ( MAXLONGLONG - this->lastPerfCounter )
                                + ( curPerfCounter.QuadPart - MINLONGLONG ) + 1;

As it is currently written we have

offset = ( MAXLONGLONG - this->lastPerfCounter )
                                + ( curPerfCounter.QuadPart + MAXLONGLONG

#define MAXLONGLONG LL_CONSTANT(0x7fffffffffffffff)
#define MINLONGLONG LL_CONSTANT(~0x7fffffffffffffff)

and so we have currently I think an off by two ticks

for example, if this is a two's complement integer with max = 127 and min -128, but also with cur = 127 and next = -128 then we
would have

offset = (127 - cur) + (next+127) = (127 - 127) + (-128+127) = -1

The result should of course be 1 so we are off by two, negative side

The correct code is as follows

            offset = ( MAXLONGLONG - this->lastPerfCounter )
                                + ( curPerfCounter.QuadPart - MINLONGLONG ) + 1;

for example, if this is a two's complement integer with max = 127 and min -128, but also with cur = 127 and next = -128 then we
would have

offset = (127 - cur) + (next - (-128) ) = (127 - 127) + (-128 - (-128) ) + 1 = 1

This maybe hasn't been noticed, other than by Alex's sharp eyes, because it was only off by 2 ticks and the performance counter counts fast. Also, the performance counter's 64 bit integer takes typically 10 to 100 years to roll over.

[Jeff Hill (johill-lanl)]

When I build win32-x86 I see this error. Perhaps the "PROD_SYS_LIBS_WIN32 = ws2_32 advapi32" line in the build system isnt working?

C:\hill\epicsInBazaar\R3.14-mirror\checkout>set EPICS_HOST_ARCH
EPICS_HOST_ARCH=win32-x86

mingw32-make -C O.win32-x86 -f ../Makefile TOP=../../.. T_A=win32-x86 install
mingw32-make[3]: Entering directory `C:/hill/epicsInBazaar/R3.14-mirror/checkout/src/libCom/O.win32-x86'
link /nologo /subsystem:windows /dll /LTCG /incremental:no /opt:ref /release /version:3.14 /implib:com.lib /out:com.dll bucketLib.obj epicsRingPointer.obj epicsRingBytes.obj postfix.obj calcPerform.obj cvtFast.obj resourc
eLib.obj epicsOnce.obj epicsSingletonMutex.obj dbmf.obj ellLib.obj envSubr.obj envData.obj errlog.obj errSymLib.obj errSymTbl.obj fdmgr.obj fdManager.obj freeListLib.obj gpHashLib.obj iocsh.obj registry.obj libComRegister.obj iocLog
.obj logClient.obj macCore.obj macEnv.obj macUtil.obj aToIPAddr.obj adjustment.obj cantProceed.obj epicsConvert.obj epicsExit.obj epicsStdlib.obj epicsString.obj truncateFile.obj ipAddrToAsciiAsynchronous.obj epicsUnitTest.obj epics
Thread.obj epicsMutex.obj epicsEvent.obj epicsTime.obj epicsMessageQueue.obj epicsMath.obj epicsGeneralTime.obj osiClockTime.obj osdSock.obj osdSockAddrReuse.obj osiSock.obj systemCallIntMech.obj epicsSocketConvertErrnoToString.obj
osdAssert.obj osdFindSymbol.obj osdInterrupt.obj osdPoolStatus.obj osdSignal.obj osdEnv.obj epicsReadline.obj epicsTempFile.obj epicsStdio.obj osdStdio.obj osdThread.obj osdMutex.obj osdEvent.obj osdTime.obj osdProcess.obj osdNetInt
f.obj osdMessageQueue.obj devLibVME.obj devLibVMEOSD.obj taskwd.obj epicsTimer.obj timer.obj timerQueue.obj timerQueueActive.obj timerQueueActiveMgr.obj timerQueuePassive.obj tsDefs.obj epicsGetopt.obj setThreadName.obj forceBadAllo
cException.obj
   Creating library com.lib and object com.exp
fdManager.obj : error LNK2001: unresolved external symbol ___WSAFDIsSet@8
fdManager.obj : error LNK2001: unresolved external symbol __imp__WSAGetLastError@0
fdManager.obj : error LNK2001: unresolved external symbol __imp__select@20
logClient.obj : error LNK2001: unresolved external symbol __imp__send@16
logClient.obj : error LNK2001: unresolved external symbol __imp__setsockopt@20
logClient.obj : error LNK2001: unresolved external symbol __imp__shutdown@8
logClient.obj : error LNK2001: unresolved external symbol __imp__htons@4
logClient.obj : error LNK2001: unresolved external symbol __imp__connect@12
aToIPAddr.obj : error LNK2001: unresolved external symbol __imp__htonl@4
osdSock.obj : error LNK2001: unresolved external symbol __imp__accept@12
osdSock.obj : error LNK2001: unresolved external symbol __imp__gethostbyname@4
osdSock.obj : error LNK2001: unresolved external symbol __imp__gethostbyaddr@12
osdSock.obj : error LNK2001: unresolved external symbol __imp__closesocket@4
osdSock.obj : error LNK2001: unresolved external symbol __imp__socket@12
osdSock.obj : error LNK2001: unresolved external symbol __imp__WSACleanup@0
osdSock.obj : error LNK2001: unresolved external symbol __imp__WSAStartup@8
osiSock.obj : error LNK2001: unresolved external symbol __imp__ntohs@4
osiSock.obj : error LNK2001: unresolved extern...

[Jeff Hill (johill-lanl)]

test results after the patch. This is maybe unlikely to change unless we can somehow simulate a rollover which would be hard to do.

C:\hill\epicsInBazaar\R3.14-mirrorII\src\libCom\test>O.WIN32-x86\
1..195
ok 1 - epicsEpoch.ansi_tm.tm_sec == 0
ok 2 - epicsEpoch.ansi_tm.tm_min == 0
ok 3 - epicsEpoch.ansi_tm.tm_hour == 0
ok 4 - epicsEpoch.ansi_tm.tm_yday == 0
ok 5 - epicsEpoch.ansi_tm.tm_year == 90
ok 6 - diff <= precisionEPICS + precisionNTP
ok 7 - nanosecond overflow throws
ok 8 - undefined => '<undefined>'
ok 9 - '%Y-%m-%d %S.%09f' => '1990-01-01 00.098765432'
ok 10 - '%S.%04f' => '00.0988'
ok 11 - '%S.%05f' => '00.09877'
ok 12 - '%S.%05f %S.%05f' => '00.09877 00.09877'
ok 13 - '%S.%05f' => '00.*'
ok 14 - '%%S.%%05f' => '%S.%05f'
ok 15 - bad format => '<invalid format>'
# Running 10 loops
# 100000 calls to epicsTime::getCurrent() averaged 0.166 usec ea
ok 16 - copy == end
ok 17 - copy <= end
ok 18 - copy >= end
ok 19 - end > begin
ok 20 - end >= begin
ok 21 - begin != end
ok 22 - begin < end
ok 23 - begin <= end
ok 24 - end - end == 0
ok 25 - end - begin ~= diff
ok 26 - begin + 0 == begin
ok 27 - begin + diff == end
ok 28 - end - 0 == end
ok 29 - end - diff == begin
ok 30 - (begin += diff) == end
ok 31 - (end -= diff) == begin
ok 32 - beginANSI + diff == end
ok 33 - beginTS + diff == end
ok 34 - copy == end
ok 35 - copy <= end
ok 36 - copy >= end
ok 37 - end > begin
ok 38 - end >= begin
ok 39 - begin != end
ok 40 - begin < end
ok 41 - begin <= end
ok 42 - end - end == 0
ok 43 - end - begin ~= diff
ok 44 - begin + 0 == begin
ok 45 - begin + diff == end
ok 46 - end - 0 == end
ok 47 - end - diff == begin
ok 48 - (begin += diff) == end
ok 49 - (end -= diff) == begin
ok 50 - beginANSI + diff == end
ok 51 - beginTS + diff == end
ok 52 - copy == end
ok 53 - copy <= end
ok 54 - copy >= end
ok 55 - end > begin
ok 56 - end >= begin
ok 57 - begin != end
ok 58 - begin < end
ok 59 - begin <= end
ok 60 - end - end == 0
ok 61 - end - begin ~= diff
ok 62 - begin + 0 == begin
ok 63 - begin + diff == end
ok 64 - end - 0 == end
ok 65 - end - diff == begin
ok 66 - (begin += diff) == end
ok 67 - (end -= diff) == begin
ok 68 - beginANSI + diff == end
ok 69 - beginTS + diff == end
ok 70 - copy == end
ok 71 - copy <= end
ok 72 - copy >= end
ok 73 - end > begin
ok 74 - end >= begin
ok 75 - begin != end
ok 76 - begin < end
ok 77 - begin <= end
ok 78 - end - end == 0
ok 79 - end - begin ~= diff
ok 80 - begin + 0 == begin
ok 81 - begin + diff == end
ok 82 - end - 0 == end
ok 83 - end - diff == begin
ok 84 - (begin += diff) == end
ok 85 - (end -= diff) == begin
ok 86 - beginANSI + diff == end
ok 87 - beginTS + diff == end
ok 88 - copy == end
ok 89 - copy <= end
ok 90 - copy >= end
ok 91 - end > begin
ok 92 - end >= begin
ok 93 - begin != end
ok 94 - begin < end
ok 95 - begin <= end
ok 96 - end - end == 0
ok 97 - end - begin ~= diff
ok 98 - begin + 0 == begin
ok 99 - begin + diff == end
ok 100 - end - 0 == end
ok 101 - end - diff == begin
ok 102 - (begin += diff) == end
ok 103 - (end -= diff) == begin
ok 104 - beginANSI + diff == end
ok 105 - beginTS + diff == end
ok 106 - copy == end
ok 107 - copy <= end
ok 108 - copy >= end
ok 109 - end > begin
ok 110 - end >...

[Jeff Hill (johill-lanl)]

and the timer test

C:\hill\epicsInBazaar\R3.14-mirrorII\src\libCom\test>O.WIN32-x86\epicsTimerTest
1..40
# Testing timer accuracy
ok 1 - timerCount == nTimers
ok 2 - percentError < messageThresh
ok 3 - percentError < messageThresh
ok 4 - percentError < messageThresh
ok 5 - percentError < messageThresh
ok 6 - percentError < messageThresh
ok 7 - percentError < messageThresh
ok 8 - percentError < messageThresh
ok 9 - percentError < messageThresh
ok 10 - percentError < messageThresh
ok 11 - percentError < messageThresh
ok 12 - percentError < messageThresh
ok 13 - percentError < messageThresh
ok 14 - percentError < messageThresh
ok 15 - percentError < messageThresh
ok 16 - percentError < messageThresh
ok 17 - percentError < messageThresh
ok 18 - percentError < messageThresh
ok 19 - percentError < messageThresh
ok 20 - percentError < messageThresh
ok 21 - percentError < messageThresh
ok 22 - percentError < messageThresh
ok 23 - percentError < messageThresh
ok 24 - percentError < messageThresh
ok 25 - percentError < messageThresh
ok 26 - percentError < messageThresh
# average timer delay error -7.297385 ms
# Testing timer cancellation
ok 27 - timerCount == nTimers
ok 28 - cancelVerify::expireCount == 0
ok 29 - cancelVerify::cancelCount == 0
# starting 25 timers
ok 30 - cancelVerify::expireCount == 0
ok 31 - cancelVerify::cancelCount == 0
# cancelling timers
ok 32 - cancelVerify::expireCount == 0
ok 33 - cancelVerify::cancelCount == nTimers
# waiting until after timers should have expired
ok 34 - cancelVerify::expireCount == 0
ok 35 - cancelVerify::cancelCount == nTimers
# Testing timer destruction in expire()
ok 36 - timerCount == nTimers
ok 37 - expireDestroyVerify::destroyCount == 0
# starting 25 timers
# waiting until all timers should have expired
ok 38 - expireDestroyVerify::destroyCount == nTimers
# Testing periodic timers
ok 39 - timerCount == nTimers
# starting 25 timers
# waiting until all timers should have expired
ok 40 - All timers expiring

    Results
    =======
       Tests: 40
      Passed: 40 = 100.00%

[Jeff Hill (johill-lanl)]

committed this patch

C:\hill\epicsInBazaar\R3.14-mirrorII\src\libCom>bzr diff
Connected (version 2.0, client Twisted)
Authentication (publickey) successful!
Secsh channel 1 opened.
=== modified file 'src/libCom/osi/os/WIN32/osdTime.cpp'
--- src/libCom/osi/os/WIN32/osdTime.cpp 2011-01-15 00:56:49 +0000
+++ src/libCom/osi/os/WIN32/osdTime.cpp 2011-11-10 20:58:14 +0000
@@ -60,6 +60,7 @@
 // for mingw
 #if !defined ( MAXLONGLONG )
 #define MAXLONGLONG LL_CONSTANT(0x7fffffffffffffff)
+#define MINLONGLONG LL_CONSTANT(~0x7fffffffffffffff)
 #endif

 static const LONGLONG epicsEpochInFileTime = LL_CONSTANT(0x01b41e2a18d64000);
@@ -346,7 +347,7 @@
             // counter resolution will more than likely improve over time.
             //
             offset = ( MAXLONGLONG - this->lastPerfCounter )
- + ( curPerfCounter.QuadPart + MAXLONGLONG );
+ + ( curPerfCounter.QuadPart - MINLONGLONG ) + 1;
         }
         if ( offset < MAXLONGLONG / EPICS_TIME_TICKS_PER_SEC ) {
             offset *= EPICS_TIME_TICKS_PER_SEC;
@@ -424,7 +425,7 @@
         // counter resolution will more than likely improve over time.
         //
         perfCounterDiff = ( MAXLONGLONG - this->lastPerfCounterPLL )
- + ( curPerfCounter.QuadPart + MAXLONGLONG );
+ + ( curPerfCounter.QuadPart - MINLONGLONG ) + 1;
     }
     this->lastPerfCounterPLL = curPerfCounter.QuadPart;

@@ -473,7 +474,7 @@
         //
         perfCounterDiffSinceLastFetch =
             ( MAXLONGLONG - this->lastPerfCounter )
- + ( curPerfCounter.QuadPart + MAXLONGLONG );
+ + ( curPerfCounter.QuadPart - MINLONGLONG ) + 1;
     }

     // Update the current estimated time.