Jeff,

We're currently using the portable CA server on PharLap(one realtime 
Windows). We're actually using only 4 components: cas.dll, gdd.dll, 
ca.dll, Com.dll. We found this thread synchronization during the debugging 
of another Bug 697516. We simply put two lines of code like this:

printf("curPerfCounter.QuadPart(%I64X), this->lastPerfCounter(%I64X)\n");
if ( curPerfCounter.QuadPart < this->lastPerfCounter ) getchar();

before line 444 at file base-3.14.9\src\libCom\osi\os\WIN32\osdTime.cpp. 
The currentTime::expire() is called every 1 second. Within 1 minute, we 
could catch one abnormal 'curPerfCounter.QuadPart < this->lastPerfCounter' 
case.

Thanks,

Alex




From:
Jeff Hill <email address hidden>
To:
<email address hidden>
Date:
01/07/2011 12:11 AM
Subject:
RE: [Bug 697509] Re: Thread synchronization     issue   in 
libCom/osi/os/WIN32/osdTime.cpp
Sent by:
<email address hidden>



Hi Alex,

Yes, it did run on 4 core (8 virtual core) machine, an
Intel windows 7 workstation.

How did you detect a failure?

Jeff
______________________________________________________
Jeffrey O. Hill           Email        <email address hidden>
LANL MS H820              Voice        505 665 1831
Los Alamos NM 87545 USA   FAX          505 665 5107

Message content: TSPA

With sufficient thrust, pigs fly just fine. However, this is
not necessarily a good idea. It is hard to be sure where they
are going to land, and it could be dangerous sitting under them
as they fly overhead. -- RFC 1925


> -----Original Message-----
> From: <email address hidden> [mailto:<email address hidden>] On Behalf Of
> Alex Chen
> Sent: Wednesday, January 05, 2011 11:23 PM
> To: <email address hidden>
> Subject: Re: [Bug 697509] Re: Thread synchronization issue in
> libCom/osi/os/WIN32/osdTime.cpp
> 
> Did this test run on a multicore machine?
> 
> Thanks,
> 
> Alex
> 
> 
> 
> From:
> Jeff Hill <email address hidden>
> To:
> <email address hidden>
> Date:
> 01/06/2011 09:45 AM
> Subject:
> [Bug 697509] Re: Thread synchronization issue in
> libCom/osi/os/WIN32/osdTime.cpp
> Sent by:
> <email address hidden>
> 
> 
> the test results after making that change (I notice no change in the
> test output before or after this change)
> 
> C:\hill\epicsInBazaar\R3.14\trunk\src\libCom\test\O.WIN32-
> x86>epicsTimeTest.exe
> 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.283 usec each
> 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 >= begin
> ok 111 - begin != end
> ok 112 - begin < end
> ok 113 - begin <= end
> ok 114 - end - end == 0
> ok 115 - end - begin ~= diff
> ok 116 - begin + 0 == begin
> ok 117 - begin + diff == end
> ok 118 - end - 0 == end
> ok 119 - end - diff == begin
> ok 120 - (begin += diff) == end
> ok 121 - (end -= diff) == begin
> ok 122 - beginANSI + diff == end
> ok 123 - beginTS + diff == end
> ok 124 - copy == end
> ok 125 - copy <= end
> ok 126 - copy >= end
> ok 127 - end > begin
> ok 128 - end >= begin
> ok 129 - begin != end
> ok 130 - begin < end
> ok 131 - begin <= end
> ok 132 - end - end == 0
> ok 133 - end - begin ~= diff
> ok 134 - begin + 0 == begin
> ok 135 - begin + diff == end
> ok 136 - end - 0 == end
> ok 137 - end - diff == begin
> ok 138 - (begin += diff) == end
> ok 139 - (end -= diff) == begin
> ok 140 - beginANSI + diff == end
> ok 141 - beginTS + diff == end
> ok 142 - copy == end
> ok 143 - copy <= end
> ok 144 - copy >= end
> ok 145 - end > begin
> ok 146 - end >= begin
> ok 147 - begin != end
> ok 148 - begin < end
> ok 149 - begin <= end
> ok 150 - end - end == 0
> ok 151 - end - begin ~= diff
> ok 152 - begin + 0 == begin
> ok 153 - begin + diff == end
> ok 154 - end - 0 == end
> ok 155 - end - diff == begin
> ok 156 - (begin += diff) == end
> ok 157 - (end -= diff) == begin
> ok 158 - beginANSI + diff == end
> ok 159 - beginTS + diff == end
> ok 160 - copy == end
> ok 161 - copy <= end
> ok 162 - copy >= end
> ok 163 - end > begin
> ok 164 - end >= begin
> ok 165 - begin != end
> ok 166 - begin < end
> ok 167 - begin <= end
> ok 168 - end - end == 0
> ok 169 - end - begin ~= diff
> ok 170 - begin + 0 == begin
> ok 171 - begin + diff == end
> ok 172 - end - 0 == end
> ok 173 - end - diff == begin
> ok 174 - (begin += diff) == end
> ok 175 - (end -= diff) == begin
> ok 176 - beginANSI + diff == end
> ok 177 - beginTS + diff == end
> ok 178 - copy == end
> ok 179 - copy <= end
> ok 180 - copy >= end
> ok 181 - end > begin
> ok 182 - end >= begin
> ok 183 - begin != end
> ok 184 - begin < end
> ok 185 - begin <= end
> ok 186 - end - end == 0
> ok 187 - end - begin ~= diff
> ok 188 - begin + 0 == begin
> ok 189 - begin + diff == end
> ok 190 - end - 0 == end
> ok 191 - end - diff == begin
> ok 192 - (begin += diff) == end
> ok 193 - (end -= diff) == begin
> ok 194 - beginANSI + diff == end
> ok 195 - beginTS + diff == end
> 
>     Results
>     =======
>        Tests: 195
>       Passed: 195 = 100.00%
> 
> --
> You received this bug notification because you are a direct subscriber
> of the bug.
> https://bugs.launchpad.net/bugs/697509
> 
> Title:
>   Thread synchronization issue in libCom/osi/os/WIN32/osdTime.cpp
> 
> Status in EPICS Base:
>   New
> 
> Bug description:
>   EPICS Base version 3.14.9
> 
> File: /src/libCom/osi/os/WIN32/osdTime.cpp
> 
> Function: epicsTimerNotify::expireStatus currentTime::expire ( const
> epicsTime & )
> 
> Line 444:  if ( curPerfCounter.QuadPart >= this->lastPerfCounter )
> 
> Problem: There is a thread synchronization issue which causes the
> 'curPerfCounter.QuadPart' to be less than the 'this->lastPerfCounter',
> and
> we will handle it as a roll over case. But actually this is not a roll
> over case, the 'this->lastPerfCounter' is changed by another thread 
which
> executes the 'void currentTime::getCurrentTime ( epicsTimeStamp & dest )
> '
> 
> How to fix:
> We can move line 441 ' EnterCriticalSection ( & this->mutex );' to the
> beginning of this function.
> 
> 
> To unsubscribe from this bug, go to:
> https://bugs.launchpad.net/epics-base/+bug/697509/+subscribe
> 
> --
> You received this bug notification because you are a direct subscriber
> of the bug.
> https://bugs.launchpad.net/bugs/697509
> 
> Title:
>   Thread synchronization issue in libCom/osi/os/WIN32/osdTime.cpp
> 
> Status in EPICS Base:
>   New
> 
> Bug description:
>   EPICS Base version 3.14.9
> 
> File: /src/libCom/osi/os/WIN32/osdTime.cpp
> 
> Function: epicsTimerNotify::expireStatus currentTime::expire ( const
> epicsTime & )
> 
> Line 444:  if ( curPerfCounter.QuadPart >= this->lastPerfCounter )
> 
> Problem: There is a thread synchronization issue which causes the
> 'curPerfCounter.QuadPart' to be less than the 'this->lastPerfCounter',
> and we will handle it as a roll over case. But actually this is not a
> roll over case, the 'this->lastPerfCounter' is changed by another thread
> which executes the 'void currentTime::getCurrentTime ( epicsTimeStamp &
> dest ) '
> 
> How to fix:
> We can move line 441 ' EnterCriticalSection ( & this->mutex );' to the
> beginning of this function.
> 
> 
> 
> To unsubscribe from this bug, go to:
> https://bugs.launchpad.net/epics-base/+bug/697509/+subscribe

-- 
You received this bug notification because you are a direct subscriber
of the bug.
https://bugs.launchpad.net/bugs/697509

Title:
  Thread synchronization issue in libCom/osi/os/WIN32/osdTime.cpp

Status in EPICS Base:
  New

Bug description:
  EPICS Base version 3.14.9

File: /src/libCom/osi/os/WIN32/osdTime.cpp

Function: epicsTimerNotify::expireStatus currentTime::expire ( const 
epicsTime & )

Line 444:  if ( curPerfCounter.QuadPart >= this->lastPerfCounter )

Problem: There is a thread synchronization issue which causes the 
'curPerfCounter.QuadPart' to be less than the 'this->lastPerfCounter', and 
we will handle it as a roll over case. But actually this is not a roll 
over case, the 'this->lastPerfCounter' is changed by another thread which 
executes the 'void currentTime::getCurrentTime ( epicsTimeStamp & dest ) '

How to fix:
We can move line 441 ' EnterCriticalSection ( & this->mutex );' to the 
beginning of this function.



To unsubscribe from this bug, go to:
https://bugs.launchpad.net/epics-base/+bug/697509/+subscribe