/*************************************************************************\ * Copyright (c) 2008 UChicago Argonne LLC, as Operator of Argonne * National Laboratory. * Copyright (c) 2002 The Regents of the University of California, as * Operator of Los Alamos National Laboratory. * Copyright (c) 2013 ITER Organization. * SPDX-License-Identifier: EPICS * EPICS BASE is distributed subject to a Software License Agreement found * in file LICENSE that is included with this distribution. \*************************************************************************/ /* Author: Marty Kraimer Date: 26JAN2000 */ #include #include #include #include #include #include #include "callback.h" #include "cantProceed.h" #include "epicsThread.h" #include "epicsEvent.h" #include "epicsTime.h" #include "epicsUnitTest.h" #include "testMain.h" /* * This test checks both immediate and delayed callbacks in two steps. * In the first step (pass1) NCALLBACKS immediate callbacks are queued. * As each is run it starts a second delayed callback (pass2). * The last delayed callback which runs signals an epicsEvent * to the main thread. * * Two time intervals are measured. The time to queue and run each of * the immediate callbacks, and the actual delay of the delayed callback. * * Slow callbacks no longer fail the test, they just emit a diagnostic. */ #define NCALLBACKS 169 #define DELAY_QUANTUM 0.25 #define TEST_DELAY(i) ((i / NUM_CALLBACK_PRIORITIES) * DELAY_QUANTUM) typedef struct myPvt { epicsCallback cb1; epicsCallback cb2; epicsTimeStamp pass1Time; epicsTimeStamp pass2Time; double delay; int pass; int resultFail; } myPvt; static epicsEventId finished; static void myCallback(epicsCallback *pCallback) { myPvt *pmyPvt; callbackGetUser(pmyPvt, pCallback); pmyPvt->pass++; if (pmyPvt->pass == 1) { epicsTimeGetCurrent(&pmyPvt->pass1Time); callbackRequestDelayed(&pmyPvt->cb2, pmyPvt->delay); } else if (pmyPvt->pass == 2) { epicsTimeGetCurrent(&pmyPvt->pass2Time); } else { pmyPvt->resultFail = 1; return; } } static void finalCallback(epicsCallback *pCallback) { myCallback(pCallback); epicsEventSignal(finished); } static void updateStats(double *stats, double val) { if (stats[0] > val) stats[0] = val; if (stats[1] < val) stats[1] = val; stats[2] += val; stats[3] += pow(val, 2.0); stats[4] += 1.; } static void printStats(double *stats, const char* tag) { testDiag("Priority %4s min/avg/max/sigma = %f / %f / %f / %f", tag, stats[0], stats[2]/stats[4], stats[1], sqrt(stats[4]*stats[3]-pow(stats[2], 2.0))/stats[4]); } MAIN(callbackParallelTest) { myPvt *pcbt[NCALLBACKS]; epicsTimeStamp start; int noCpus = epicsThreadGetCPUs(); int i, j, slowups, faults; /* Statistics: min/max/sum/sum^2/n for each priority */ double setupError[NUM_CALLBACK_PRIORITIES][5]; double timeError[NUM_CALLBACK_PRIORITIES][5]; double defaultError[5] = {1,-1,0,0,0}; for (i = 0; i < NUM_CALLBACK_PRIORITIES; i++) for (j = 0; j < 5; j++) setupError[i][j] = timeError[i][j] = defaultError[j]; testPlan(2); testDiag("Starting %d parallel callback threads", noCpus); callbackParallelThreads(noCpus, ""); callbackInit(); epicsThreadSleep(1.0); finished = epicsEventMustCreate(epicsEventEmpty); for (i = 0; i < NCALLBACKS ; i++) { pcbt[i] = callocMustSucceed(1, sizeof(myPvt), "pcbt"); callbackSetCallback(myCallback, &pcbt[i]->cb1); callbackSetCallback(myCallback, &pcbt[i]->cb2); callbackSetUser(pcbt[i], &pcbt[i]->cb1); callbackSetUser(pcbt[i], &pcbt[i]->cb2); callbackSetPriority(i % NUM_CALLBACK_PRIORITIES, &pcbt[i]->cb1); callbackSetPriority(i % NUM_CALLBACK_PRIORITIES, &pcbt[i]->cb2); pcbt[i]->delay = TEST_DELAY(i); pcbt[i]->pass = 0; } /* Last callback is special */ callbackSetCallback(finalCallback, &pcbt[NCALLBACKS-1]->cb2); callbackSetPriority(0, &pcbt[NCALLBACKS-1]->cb1); callbackSetPriority(0, &pcbt[NCALLBACKS-1]->cb2); pcbt[NCALLBACKS-1]->delay = TEST_DELAY(NCALLBACKS) + 1.0; pcbt[NCALLBACKS-1]->pass = 0; testOk(epicsTimeGetCurrent(&start)==epicsTimeOK, "Time-of-day clock Ok"); for (i = 0; i < NCALLBACKS ; i++) { callbackRequest(&pcbt[i]->cb1); } testDiag("Waiting %.02f sec", pcbt[NCALLBACKS-1]->delay); epicsEventWait(finished); slowups = 0; faults = 0; for (i = 0; i < NCALLBACKS ; i++) { if(pcbt[i]->resultFail || pcbt[i]->pass!=2) testDiag("callback setup fault #%d: pass = %d for delay = %.02f", ++faults, pcbt[i]->pass, pcbt[i]->delay); else { double delta = epicsTimeDiffInSeconds(&pcbt[i]->pass1Time, &start); if (fabs(delta) >= 0.05) { slowups++; testDiag("callback %.02f setup time |%f| >= 0.05 seconds", pcbt[i]->delay, delta); } updateStats(setupError[i%NUM_CALLBACK_PRIORITIES], delta); } } testOk(faults == 0, "%d faults during callback setup", faults); if (slowups) testDiag("%d slowups during callback setup", slowups); slowups = 0; for (i = 0; i < NCALLBACKS ; i++) { double delta, error; if(pcbt[i]->resultFail || pcbt[i]->pass!=2) continue; delta = epicsTimeDiffInSeconds(&pcbt[i]->pass2Time, &pcbt[i]->pass1Time); error = delta - pcbt[i]->delay; if (fabs(error) >= 0.05) { slowups++; testDiag("delay %.02f seconds, delay error |%.04f| >= 0.05", pcbt[i]->delay, error); } updateStats(timeError[i%NUM_CALLBACK_PRIORITIES], error); } if (slowups) testDiag("%d slowups during callback setup", slowups); testDiag("Setup time statistics"); printStats(setupError[0], "LOW"); printStats(setupError[1], "MID"); printStats(setupError[2], "HIGH"); testDiag("Delay time statistics"); printStats(timeError[0], "LOW"); printStats(timeError[1], "MID"); printStats(timeError[2], "HIGH"); for (i = 0; i < NCALLBACKS ; i++) { free(pcbt[i]); } callbackStop(); callbackCleanup(); return testDone(); }