diff --git a/documentation/RELEASE_NOTES.html b/documentation/RELEASE_NOTES.html index dab0a01e6..10daf1016 100644 --- a/documentation/RELEASE_NOTES.html +++ b/documentation/RELEASE_NOTES.html @@ -13,6 +13,31 @@ +
The iocInit code now performs a sanity check of the current time +returned by the generalTime subsystem and will print a warning if the wall-clock +time returned has not been initialized yet. This is just a warning message; when +a time provider does synchonize the IOC will subsequently pick up and use the +correct time. This check code also primes the registered event system provider +if there is one so the epicsTimeGetEventInt() routine will work on IOCs +that ask for event time within an interrupt service routine.
+ +The osiClockTime provider's synchronization thread (which is only used on +some embedded targets) will now poll the other time providers at 1Hz until the +first time it manages to get a successful timestamp, after which it will poll +for updates every 60 seconds as before.
+ +The routine generalTimeGetExceptPriority() was designed for use by +backup (lower priority) time providers like the osiClockTime provider which do +not have their own absolute time reference and rely on other providers for an +absolute time source. This routine no longer implements the ratchet mechanism +that prevented the time it returned from going backwards. If the backup clock's +tick-timer runs fast the synchronization of the backup time provider would never +allow it to be corrected backwards when the ratchet was in place. The regular +epicsTimeGetCurrent() API still uses the ratchet mechanism, so this +change will not cause the IOC to see time going backwards.
+The build configuration files for builds using the Microsoft compilers have diff --git a/src/libCom/osi/epicsGeneralTime.c b/src/libCom/osi/epicsGeneralTime.c index 8ef8a73cc..7c94b81d5 100644 --- a/src/libCom/osi/epicsGeneralTime.c +++ b/src/libCom/osi/epicsGeneralTime.c @@ -1,5 +1,5 @@ /*************************************************************************\ -* Copyright (c) 2009 UChicago Argonne LLC, as Operator of Argonne +* Copyright (c) 2016 UChicago Argonne LLC, as Operator of Argonne * National Laboratory. * Copyright (c) 2008 Diamond Light Source Ltd * Copyright (c) 2004 Oak Ridge National Laboratory @@ -31,6 +31,17 @@ #include "generalTimeSup.h" #include "epicsGeneralTime.h" +/* Change 'undef' to 'define' to turn on debug statements: */ +#undef DEBUG_GENERAL_TIME + +#ifdef DEBUG_GENERAL_TIME + int generalTimeDebug = 10; +# define IFDEBUG(n) \ + if (generalTimeDebug >= n) /* block or statement */ +#else +# define IFDEBUG(n) \ + if(0) /* Compiler will elide the block or statement */ +#endif /* Declarations */ @@ -65,6 +76,7 @@ static struct { static epicsThreadOnceId onceId = EPICS_THREAD_ONCE_INIT; +static const char * const tsfmt = "%Y-%m-%d %H:%M:%S.%09f"; /* Implementation */ @@ -75,6 +87,9 @@ static void generalTime_InitOnce(void *dummy) ellInit(>Pvt.eventProviders); gtPvt.eventListLock = epicsMutexMustCreate(); + + IFDEBUG(1) + printf("General Time Initialized\n"); } void generalTime_Init(void) @@ -90,44 +105,103 @@ int generalTimeGetExceptPriority(epicsTimeStamp *pDest, int *pPrio, int ignore) generalTime_Init(); + IFDEBUG(2) + printf("generalTimeGetExceptPriority(ignore=%d)\n", ignore); + epicsMutexMustLock(gtPvt.timeListLock); for (ptp = (gtProvider *)ellFirst(>Pvt.timeProviders); ptp; ptp = (gtProvider *)ellNext(&ptp->node)) { - if (ptp->priority == ignore) + if ((ignore > 0 && ptp->priority == ignore) || + (ignore < 0 && ptp->priority != -ignore)) continue; status = ptp->get.Time(pDest); if (status == epicsTimeOK) { - /* check time is monotonic */ - if (epicsTimeGreaterThanEqual(pDest, >Pvt.lastProvidedTime)) { - gtPvt.lastProvidedTime = *pDest; - if (ignore == 0) - gtPvt.lastTimeProvider = ptp; - if (pPrio) - *pPrio = ptp->priority; - } else { - int key; - *pDest = gtPvt.lastProvidedTime; - if (pPrio) - *pPrio = gtPvt.lastTimeProvider->priority; - key = epicsInterruptLock(); - gtPvt.ErrorCounts++; - epicsInterruptUnlock(key); - } + /* No ratchet, time from this routine may go backwards */ + if (pPrio) + *pPrio = ptp->priority; break; } + else IFDEBUG(2) + printf("gTGExP provider '%s' returned error\n", ptp->name); } - if (status == epicsTimeERROR && - ignore == 0) - gtPvt.lastTimeProvider = NULL; epicsMutexUnlock(gtPvt.timeListLock); + IFDEBUG(2) { + if (ptp && status == epicsTimeOK) { + char buff[40]; + + epicsTimeToStrftime(buff, sizeof(buff), tsfmt, pDest); + printf("gTGExP returning %s from provider '%s'\n", + buff, ptp->name); + } + else + printf("gTGExP returning error\n"); + } + return status; } int epicsShareAPI epicsTimeGetCurrent(epicsTimeStamp *pDest) { - return generalTimeGetExceptPriority(pDest, NULL, 0); + gtProvider *ptp; + int status = epicsTimeERROR; + epicsTimeStamp ts; + + generalTime_Init(); + + IFDEBUG(20) + printf("epicsTimeGetCurrent()\n"); + + epicsMutexMustLock(gtPvt.timeListLock); + for (ptp = (gtProvider *)ellFirst(>Pvt.timeProviders); + ptp; ptp = (gtProvider *)ellNext(&ptp->node)) { + + status = ptp->get.Time(&ts); + if (status == epicsTimeOK) { + /* check time is monotonic */ + if (epicsTimeGreaterThanEqual(&ts, >Pvt.lastProvidedTime)) { + *pDest = ts; + gtPvt.lastProvidedTime = ts; + gtPvt.lastTimeProvider = ptp; + } else { + int key; + + *pDest = gtPvt.lastProvidedTime; + key = epicsInterruptLock(); + gtPvt.ErrorCounts++; + epicsInterruptUnlock(key); + + IFDEBUG(10) { + char last[40], buff[40]; + + epicsTimeToStrftime(last, sizeof(last), tsfmt, + >Pvt.lastProvidedTime); + epicsTimeToStrftime(buff, sizeof(buff), tsfmt, &ts); + printf("eTGC provider '%s' returned older time\n" + " %s, using %s instead\n", ptp->name, buff, last); + } + } + break; + } + } + if (status == epicsTimeERROR) + gtPvt.lastTimeProvider = NULL; + epicsMutexUnlock(gtPvt.timeListLock); + + IFDEBUG(20) { + if (ptp && status == epicsTimeOK) { + char buff[40]; + + epicsTimeToStrftime(buff, sizeof(buff), tsfmt, &ts); + printf("eTGC returning %s from provider '%s'\n", + buff, ptp->name); + } + else + printf("eTGC returning error\n"); + } + + return status; } int epicsTimeGetCurrentInt(epicsTimeStamp *pDest) @@ -135,7 +209,11 @@ int epicsTimeGetCurrentInt(epicsTimeStamp *pDest) gtProvider *ptp = gtPvt.lastTimeProvider; if (ptp == NULL || - ptp->getInt.Time == NULL) return epicsTimeERROR; + ptp->getInt.Time == NULL) { + IFDEBUG(20) + epicsInterruptContextMessage("eTGCInt: No support\n"); + return epicsTimeERROR; + } return ptp->getInt.Time(pDest); } @@ -146,9 +224,13 @@ static int generalTimeGetEventPriority(epicsTimeStamp *pDest, int eventNumber, { gtProvider *ptp; int status = epicsTimeERROR; + epicsTimeStamp ts; generalTime_Init(); + IFDEBUG(2) + printf("generalTimeGetEventPriority(eventNum=%d)\n", eventNumber); + if ((eventNumber < 0 || eventNumber >= NUM_TIME_EVENTS) && (eventNumber != epicsTimeEventBestTime)) return status; @@ -157,27 +239,40 @@ static int generalTimeGetEventPriority(epicsTimeStamp *pDest, int eventNumber, for (ptp = (gtProvider *)ellFirst(>Pvt.eventProviders); ptp; ptp = (gtProvider *)ellNext(&ptp->node)) { - status = ptp->get.Event(pDest, eventNumber); - if (status != epicsTimeERROR) { + status = ptp->get.Event(&ts, eventNumber); + if (status == epicsTimeOK) { gtPvt.lastEventProvider = ptp; if (pPrio) *pPrio = ptp->priority; if (eventNumber == epicsTimeEventBestTime) { - if (epicsTimeGreaterThanEqual(pDest, + if (epicsTimeGreaterThanEqual(&ts, >Pvt.lastProvidedBestTime)) { - gtPvt.lastProvidedBestTime = *pDest; + *pDest = ts; + gtPvt.lastProvidedBestTime = ts; } else { int key; *pDest = gtPvt.lastProvidedBestTime; key = epicsInterruptLock(); gtPvt.ErrorCounts++; epicsInterruptUnlock(key); + + IFDEBUG(10) { + char last[40], buff[40]; + + epicsTimeToStrftime(last, sizeof(last), tsfmt, + >Pvt.lastProvidedBestTime); + epicsTimeToStrftime(buff, sizeof(buff), tsfmt, &ts); + printf("gTGEvP provider '%s' returned older time\n" + " %s, using %s instead\n", + ptp->name, buff, last); + } } } else { if (epicsTimeGreaterThanEqual(pDest, >Pvt.eventTime[eventNumber])) { - gtPvt.eventTime[eventNumber] = *pDest; + *pDest = ts; + gtPvt.eventTime[eventNumber] = ts; } else { int key; *pDest = gtPvt.eventTime[eventNumber]; @@ -185,14 +280,39 @@ static int generalTimeGetEventPriority(epicsTimeStamp *pDest, int eventNumber, gtPvt.ErrorCounts++; epicsInterruptUnlock(key); } + + IFDEBUG(10) { + char last[40], buff[40]; + + epicsTimeToStrftime(last, sizeof(last), tsfmt, + >Pvt.lastProvidedBestTime); + epicsTimeToStrftime(buff, sizeof(buff), tsfmt, &ts); + printf("gTGEvP provider '%s' returned older time\n" + " %s, using %s instead\n", + ptp->name, buff, last); + } } break; } + else IFDEBUG(2) + printf("gTGEvP provider '%s' returned error\n", ptp->name); } if (status == epicsTimeERROR) gtPvt.lastEventProvider = NULL; epicsMutexUnlock(gtPvt.eventListLock); + IFDEBUG(10) { + if (ptp && status == epicsTimeOK) { + char buff[40]; + + epicsTimeToStrftime(buff, sizeof(buff), tsfmt, &ts); + printf("gTGEvP returning %s from provider '%s'\n", + buff, ptp->name); + } + else + printf("gTGEvP returning error\n"); + } + return status; } @@ -213,7 +333,11 @@ int epicsTimeGetEventInt(epicsTimeStamp *pDest, int eventNumber) gtProvider *ptp = gtPvt.lastEventProvider; if (ptp == NULL || - ptp->getInt.Event == NULL) return epicsTimeERROR; + ptp->getInt.Event == NULL) { + IFDEBUG(20) + epicsInterruptContextMessage("eTGEvInt: No support\n"); + return epicsTimeERROR; + } return ptp->getInt.Event(pDest, eventNumber); } @@ -284,6 +408,9 @@ int generalTimeRegisterEventProvider(const char *name, int priority, insertProvider(ptp, >Pvt.eventProviders, gtPvt.eventListLock); + IFDEBUG(1) + printf("Registered event provider '%s' at %d\n", name, priority); + return epicsTimeOK; } @@ -297,6 +424,9 @@ int generalTimeAddIntEventProvider(const char *name, int priority, ptp->getInt.Event = getEvent; + IFDEBUG(1) + printf("Event provider '%s' is interrupt-callable\n", name); + return epicsTimeOK; } @@ -321,6 +451,9 @@ int generalTimeRegisterCurrentProvider(const char *name, int priority, insertProvider(ptp, >Pvt.timeProviders, gtPvt.timeListLock); + IFDEBUG(1) + printf("Registered time provider '%s' at %d\n", name, priority); + return epicsTimeOK; } @@ -334,6 +467,9 @@ int generalTimeAddIntCurrentProvider(const char *name, int priority, ptp->getInt.Time = getTime; + IFDEBUG(1) + printf("Time provider '%s' is interrupt-callable\n", name); + return epicsTimeOK; } diff --git a/src/libCom/osi/osiClockTime.c b/src/libCom/osi/osiClockTime.c index 94bdb93d1..1463ee551 100644 --- a/src/libCom/osi/osiClockTime.c +++ b/src/libCom/osi/osiClockTime.c @@ -23,7 +23,7 @@ #include "taskwd.h" #define NSEC_PER_SEC 1000000000 -#define ClockTimeSyncInterval 60.0 +#define ClockTimeSyncInterval_value 60.0 static struct { @@ -31,6 +31,7 @@ static struct { int synchronized; epicsEventId loopEvent; epicsTimeStamp syncTime; + double ClockTimeSyncInterval; int syncFromPriority; epicsMutexId lock; } ClockTimePvt; @@ -74,6 +75,7 @@ static void ClockTime_InitOnce(void *psync) ClockTimePvt.synchronize = *(int *)psync; ClockTimePvt.loopEvent = epicsEventMustCreate(epicsEventEmpty); ClockTimePvt.lock = epicsMutexCreate(); + ClockTimePvt.ClockTimeSyncInterval = 1.0; /* First sync */ if (ClockTimePvt.synchronize) { /* Start the sync thread */ @@ -116,10 +118,10 @@ static void ClockTimeSync(void *dummy) taskwdInsert(0, NULL, NULL); for (epicsEventWaitWithTimeout(ClockTimePvt.loopEvent, - ClockTimeSyncInterval); + ClockTimePvt.ClockTimeSyncInterval); ClockTimePvt.synchronize; epicsEventWaitWithTimeout(ClockTimePvt.loopEvent, - ClockTimeSyncInterval)) { + ClockTimePvt.ClockTimeSyncInterval)) { epicsTimeStamp timeNow; int priority; @@ -138,6 +140,8 @@ static void ClockTimeSync(void *dummy) ClockTimePvt.syncFromPriority = priority; ClockTimePvt.syncTime = timeNow; epicsMutexUnlock(ClockTimePvt.lock); + + ClockTimePvt.ClockTimeSyncInterval = ClockTimeSyncInterval_value; } } @@ -195,7 +199,7 @@ int ClockTime_Report(int level) printf("Last successful sync was at %s\n", lastSync); } printf("Syncronization interval = %.0f seconds\n", - ClockTimeSyncInterval); + ClockTimePvt.ClockTimeSyncInterval); } else printf("OS Clock driver has *not* yet synchronized\n"); diff --git a/src/misc/iocInit.c b/src/misc/iocInit.c index b8f32d809..cb6aacecd 100644 --- a/src/misc/iocInit.c +++ b/src/misc/iocInit.c @@ -24,6 +24,7 @@ #include "epicsThread.h" #include "epicsPrint.h" #include "ellLib.h" +#include "epicsGeneralTime.h" #include "dbDefs.h" #include "dbBase.h" #include "caeventmask.h" @@ -69,6 +70,7 @@ static enum { /* define forward references*/ static int checkDatabase(dbBase *pdbbase); +static void checkGeneralTime(void); static void initDrvSup(void); static void initRecSup(void); static void initDevSup(void); @@ -110,6 +112,7 @@ int iocBuild(void) /* After this point, further calls to iocInit() are disallowed. */ iocState = iocBuilding; + checkGeneralTime(); taskwdInit(); callbackInit(); initHookAnnounce(initHookAfterCallbackInit); @@ -281,6 +284,22 @@ static int checkDatabase(dbBase *pdbbase) return 0; } +static void checkGeneralTime(void) +{ + epicsTimeStamp ts; + + epicsTimeGetCurrent(&ts); + if (ts.secPastEpoch < 2*24*60*60) { + static const char * const tsfmt = "%Y-%m-%d %H:%M:%S.%09f"; + char buff[40]; + + epicsTimeToStrftime(buff, sizeof(buff), tsfmt, &ts); + errlogPrintf("iocInit: Time provider has not yet synchronized.\n"); + } + + epicsTimeGetEvent(&ts, 1); /* Prime gtPvt.lastEventProvider for ISRs */ +} + static void initDrvSup(void) /* Locate all driver support entry tables */ {