Crash occurs in Com.dll if filetime is before the EPICS epoch

Reported by Alex Chen on 2011-01-05
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
EPICS Base
Medium
Unassigned
3.14
Medium
Jeff Hill

Bug Description

EPICS Base 3.14.9

File: \src\libCom\osi\epicsThread.cpp

Function: extern "C" void epicsThreadCallEntryPoint ( void * pPvt )

Problem:
If system returns a filetime before the EPICS epoch, exception std::logic_error is thrown from the 'catch' (at line 67 'catch ( std::exception & except )' and at line 83 ' catch ( ... )'). The std::logic_error is actually thrown by the 'epicsTime cur = epicsTime::getCurrent ();' complaining that epicsTimeStamp has overflow in nanosecond field.

The root cause:
File: \src\libCom\osi\os\WIN32\osdTime.cpp
Function: epicsTimerNotify::expireStatus currentTime::expire ( const epicsTime & )
Line 516:
‘LONGLONG epicsTimeFromCurrentFileTime =
        ( curFileTime.QuadPart - epicsEpochInFileTime ) *
        ET_TICKS_PER_FT_TICK;’
curFileTime could be smaller than the EPICS epoch if user changes the system time, so this will produce a wield 'epicsTimeFromCurrentFileTime' and we will assign its value to this->epicsTimeLast' at line 526 'this->epicsTimeLast = epicsTimeFromCurrentFileTime;'

We need to handle:
If the filetime returned by system is earlier than the EPICS epoch, how do we generate the 'delta' (at line 520) and adjust the perfCounterFreq accordingly.

Jeff Hill (johill-lanl) wrote :

maybe this is fixed in recent EPICS. I see code like this which seems to handle that exception?

void epicsThread :: printLastChanceExceptionMessage (
    const char * pExceptionTypeName,
    const char * pExceptionContext )
{
    char date[64];
    try {
        epicsTime cur = epicsTime :: getCurrent ();
        cur.strftime ( date, sizeof ( date ), "%a %b %d %Y %H:%M:%S.%f");
    }
    catch ( ... ) {
        strcpy ( date, "<UKN DATE>" );
    }
    char name [128];
    epicsThreadGetName ( this->id, name, sizeof ( name ) );
    errlogPrintf (
        "epicsThread: Unexpected C++ exception \"%s\" "
        "with type \"%s\" in thread \"%s\" at %s\n",
        pExceptionContext, pExceptionTypeName, name, date );
    errlogFlush ();
    // this should behave as the C++ implementation intends when an
    // exception isnt handled. If users dont like this behavior, they
    // can install an application specific unexpected handler.
    std::unexpected ();
}

Download full text (3.3 KiB)

Jeff,

Yes, the exception (overflow in nanosecond field) is caught in EPICS Base
3.14.12, but the root cause of the exception is not resolved. I've checked
the code at line 486 of base-3.14.12\src\libCom\osi\os\WIN32\osdTime.cpp,
there is still possible negative epicsTimeFromCurrentFileTime if system
returns a filetime before the EPICS Epoch. During such situations, we may
consider how to adjust the 'perfCounterFreq' which is currently
implemented by line 489 to 520 in file
base-3.14.12\src\libCom\osi\os\WIN32\osdTime.cpp.

Thanks,

Alex

From:
Jeff Hill <email address hidden>
To:
<email address hidden>
Date:
01/07/2011 12:26 AM
Subject:
[Bug 697516] Re: Crash occurs in Com.dll if filetime is before the EPICS
epoch
Sent by:
<email address hidden>

maybe this is fixed in recent EPICS. I see code like this which seems to
handle that exception?

void epicsThread :: printLastChanceExceptionMessage (
    const char * pExceptionTypeName,
    const char * pExceptionContext )
{
    char date[64];
    try {
        epicsTime cur = epicsTime :: getCurrent ();
        cur.strftime ( date, sizeof ( date ), "%a %b %d %Y %H:%M:%S.%f");
    }
    catch ( ... ) {
        strcpy ( date, "<UKN DATE>" );
    }
    char name [128];
    epicsThreadGetName ( this->id, name, sizeof ( name ) );
    errlogPrintf (
        "epicsThread: Unexpected C++ exception \"%s\" "
        "with type \"%s\" in thread \"%s\" at %s\n",
        pExceptionContext, pExceptionTypeName, name, date );
    errlogFlush ();
    // this should behave as the C++ implementation intends when an
    // exception isnt handled. If users dont like this behavior, they
    // can install an application specific unexpected handler.
    std::unexpected ();
}

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

Title:
  Crash occurs in Com.dll if filetime is before the EPICS epoch

Status in EPICS Base:
  New

Bug description:
  EPICS Base 3.14.9

File: \src\libCom\osi\epicsThread.cpp

Function: extern "C" void epicsThreadCallEntryPoint ( void * pPvt )

Problem:
If system returns a filetime before the EPICS epoch, exception
std::logic_error is thrown from the 'catch' (at line 67 'catch (
std::exception & except )' and at line 83 ' catch ( ... )'). The
std::logic_error is actually thrown by the 'epicsTime cur =
epicsTime::getCurrent ();' complaining that epicsTimeStamp has overflow in
nanosecond field.

The root cause:
File: \src\libCom\osi\os\WIN32\osdTime.cpp
Function: epicsTimerNotify::expireStatus currentTime::expire ( const
epicsTime & )
Line 516:
‘LONGLONG epicsTimeFromCurrentFileTime =
        ( curFileTime.QuadPart - epicsEpochInFileTime ) *
        ET_TICKS_PER_FT_TICK;’
curFileTime could be smaller than the EPICS epoch if user changes the
system time, so this will produce a wield 'epicsTimeFromCurrentFileTime'
and we will assign its value to this->epicsTimeLast' at line 526
'this->epicsTimeLast = epicsTimeFromCurrentFileTime;'

We need to handle:
If the filetime returned by system is earlier than the EPI...

Read more...

Jeff Hill (johill-lanl) wrote :

committed this fix

=== modified file 'src/libCom/osi/os/WIN32/osdTime.cpp'
--- src/libCom/osi/os/WIN32/osdTime.cpp 2011-11-10 21:03:01 +0000
+++ src/libCom/osi/os/WIN32/osdTime.cpp 2011-11-10 21:47:18 +0000
@@ -303,8 +303,8 @@
     }
     else {
         errlogPrintf (
- "win32 osdTime.cpp detected questionable "
- "system date prior to EPICS epoch\n" );
+ "win32 osdTime.cpp init detected questionable "
+ "system date prior to EPICS epoch, epics time will not advance\n" );
         this->epicsTimeLast = 0;
     }

@@ -483,9 +483,32 @@
             / this->perfCounterFreq;
     this->lastPerfCounter = curPerfCounter.QuadPart;

- LONGLONG epicsTimeFromCurrentFileTime =
- ( curFileTime.QuadPart - epicsEpochInFileTime ) *
- ET_TICKS_PER_FT_TICK;
+ LONGLONG epicsTimeFromCurrentFileTime;
+
+ {
+ static bool firstMessageWasSent = false;
+ if ( curFileTime.QuadPart >= epicsEpochInFileTime ) {
+ epicsTimeFromCurrentFileTime =
+ ( curFileTime.QuadPart - epicsEpochInFileTime ) *
+ ET_TICKS_PER_FT_TICK;
+ firstMessageWasSent = false;
+ }
+ else {
+ /*
+ * if the system time jumps to before the EPICS epoch
+ * then latch to the EPICS epoch printing only one
+ * warning message the first time that the issue is
+ * detected
+ */
+ if ( ! firstMessageWasSent ) {
+ errlogPrintf (
+ "win32 osdTime.cpp time PLL update detected questionable "
+ "system date prior to EPICS epoch, epics time will not advance\n" );
+ firstMessageWasSent = true;
+ }
+ epicsTimeFromCurrentFileTime = 0;
+ }
+ }

     delta = epicsTimeFromCurrentFileTime - this->epicsTimeLast;
     if ( delta > EPICS_TIME_TICKS_PER_SEC || delta < -EPICS_TIME_TICKS_PER_SEC ) {

Jeff Hill (johill-lanl) wrote :

tested with epicsTimeTest and epicsTimerTest

Changed in epics-base:
assignee: nobody → Jeff Hill (johill-lanl)
importance: Undecided → Medium
milestone: none → 3.14.branch
status: New → Confirmed
Jeff Hill (johill-lanl) wrote :

fixed by revision 12289 against R3.14 branch

Changed in epics-base:
status: Confirmed → Fix Committed
Andrew Johnson (anj) on 2011-12-12
no longer affects: epics-base/3.15
Andrew Johnson (anj) on 2011-12-12
Changed in epics-base:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers