static void delay_delta(PERF_RTdata_delay *dDelay, PERF_Private *perf)
{
if (dDelay->n < 0)
{
dDelay->n++;
}
else
{
delay_add(dDelay, TIME_DELTA(perf->time, dDelay->last_timestamp));
}
TIME_COPY(dDelay->last_timestamp, perf->time);
}
static rlm_rcode_t CC_HINT(nonnull) mod_delay(void *instance, UNUSED void *thread, REQUEST *request)
{
rlm_delay_t const *inst = instance;
struct timeval delay, resume_at, *yielded_at;
if (inst->delay) {
if (tmpl_aexpand(request, &delay, request, inst->delay, NULL, NULL) < 0) return RLM_MODULE_FAIL;
} else {
memset(&delay, 0, sizeof(delay));
}
/*
* Record the time that we yielded the request
*/
MEM(yielded_at = talloc(request, struct timeval));
if (gettimeofday(yielded_at, NULL) < 0) {
REDEBUG("Failed getting current time: %s", fr_syserror(errno));
return RLM_MODULE_FAIL;
}
/*
* Setup the delay for this request
*/
if (delay_add(request, &resume_at, yielded_at, &delay, inst->force_reschedule, inst->delay) != 0) {
return RLM_MODULE_NOOP;
}
RDEBUG3("Current time %pV, resume time %pV", fr_box_timeval(*yielded_at), fr_box_timeval(resume_at));
if (unlang_event_module_timeout_add(request, _delay_done, yielded_at, &resume_at) < 0) {
RPEDEBUG("Adding event failed");
return RLM_MODULE_FAIL;
}
return unlang_module_yield(request, mod_delay_return, mod_delay_cancel, yielded_at);
}
void __rt_Buffer(PERF_Private *perf,
unsigned long ulAddress1,
unsigned long ulAddress2,
unsigned long ulSize,
PERF_MODULETYPE eModuleAndFlags)
{
/* get real-time private structure */
PERF_RT_Private *me = perf->cip.pRT;
/* see if we care about this buffer in the rate calculation */
unsigned long module = eModuleAndFlags & PERF_ModuleMask;
/* ------------------------ RATE METRICS ------------------------ */
/* change HLMM to LLMM for detailed = 0 and 1 */
if (me->detailed < 2 && module == PERF_ModuleHLMM)
{
module = PERF_ModuleLLMM;
}
int rate = (me->detailed == 2) ||
(me->detailed == 0 &&
(eModuleAndFlags == me->only_moduleandflags && ulSize >= 8)) ||
(me->detailed == 1 &&
((module == PERF_ModuleHardware || module == PERF_ModuleLLMM)));
if (rate && me->dRate && (!me->needSteadyState || me->steadyState))
{
/* change encoded filled frame sizes to 0xBEEFED, as they tend to
have varying sizes and thus not be counted */
unsigned long sending = PERF_GetXferSendRecv(eModuleAndFlags);
unsigned long size = ulSize;
if ((me->encoder || me->decoder) && !PERF_IsXfering(sending))
{
/* reverse sending direction to common layer or socket node */
if (module >= PERF_ModuleCommonLayer &&
module <= PERF_ModuleSocketNode)
{
sending ^= PERF_FlagSending;
}
if ((me->encoder && (sending == PERF_FlagSending)) ||
(me->decoder && (sending == PERF_FlagReceived)))
{
size = size ? 0xBEEFED : 0;
}
}
/* see if we are tracking this buffer size */
int i, j = -1; /* j is one of the lest used indexes */
for (i=0; i < me->nDRate; i++)
{
if (me->dRate[i].modulesAndFlags == eModuleAndFlags &&
me->dRate[i].size == size) break;
if (j < 0 || me->dRate[i].n < me->dRate[j].n)
{
j = i;
}
}
/* if we are not yet tracking this buffer, see if we can track
it. */
if (i == me->nDRate)
{
/* we have space to track it */
if (i < me->maxDRate)
{
me->nDRate++;
}
/* if we cannot replace another rate, we don't track it */
else if (j < 0 || me->dRate[j].n < 2)
{
i = me->maxDRate;
}
else
{
i = j;
}
/* start tracking */
if (i < me->maxDRate)
{
me->dRate[i].modulesAndFlags = eModuleAndFlags;
me->dRate[i].size = size;
me->dRate[i].xx = me->dRate[i].x = me->dRate[i].n = 0;
me->dRate[i].txx = me->dRate[i].tx = me->dRate[i].tn = me->dRate[i].tn0 = 0;
me->dRate[i].axx = me->dRate[i].ax = me->dRate[i].an = 0;
me->dRate[i].skip = me->needSteadyState ? 0 : 4;
TIME_COPY(me->dRate[i].last_timestamp, perf->time);
TIME_COPY(me->dRate[i].last_reporting, perf->time);
}
}
else
{
if (me->dRate[i].skip == 0)
{
/* see if we passed our granularity */
int steps = TIME_DELTA(perf->time, me->dRate[i].last_reporting);
if (steps >= me->granularity)
{
steps /= me->granularity;
/* unless debug bit 4 is set, ignore temporal statistics if
we passed the last time by more than a second, and less than
the minimul frames were processed in this burst so far, and
the last fps was less than 1. */
if (!(me->debug & 4) &&
(me->dRate[i].tn0 < MIN_FRAMES_FOR_RATE) &&
(me->dRate[i].tn < me->granularity * steps))
{
if (me->debug & 256)
{
fprintf(me->fRt, "rtPERF: [%ld] IGNORED (steps=%d, tn0=%ld, tn=%ld)\n",
TIME_DELTA(me->dRate[i].last_reporting, me->first_time)/1000000,
steps, me->dRate[i].tn0, me->dRate[i].tn);
}
me->dRate[i].txx = me->dRate[i].tx = me->dRate[i].tn = me->dRate[i].tn0 = 0;
TIME_INCREASE(me->dRate[i].last_reporting, me->granularity * steps);
steps = 0;
}
else if (me->debug & 256)
{
fprintf(me->fRt, "rtPERF: [%ld] not-ignored (steps=%d, tn0=%ld, tn=%ld)\n",
TIME_DELTA(me->dRate[i].last_reporting, me->first_time)/1000000,
steps, me->dRate[i].tn0, me->dRate[i].tn);
}
/* see if we surpassed our granularity. if yes, calculate
temporal statistics */
while (steps)
{
/* count temporal rate */
count_temporal_rate(perf->ulID, me, me->dRate + i);
TIME_INCREASE(me->dRate[i].last_reporting, me->granularity);
steps--;
}
}
/* rate is */
unsigned long delta = TIME_DELTA(perf->time, me->dRate[i].last_timestamp);
me->dRate[i].x += delta;
me->dRate[i].tx += delta;
me->dRate[i].xx += delta * (double) delta;
me->dRate[i].txx += delta * (double) delta;
me->dRate[i].n ++;
me->dRate[i].tn ++;
me->dRate[i].tn0 ++;
}
else
{
me->dRate[i].skip--;
if (me->dRate[i].skip == 0)
{
TIME_COPY(me->dRate[i].last_reporting, perf->time);
me->dRate[i].txx = me->dRate[i].tx = me->dRate[i].tn = 0;
}
}
TIME_COPY(me->dRate[i].last_timestamp, perf->time);
}
}
/* ------------------------ SHOT-TO-SHOT METRICS ------------------------ */
if (me->dSTS)
{
if (eModuleAndFlags == (PERF_FlagSending | PERF_FlagFrame | PERF_ModuleHardware))
{
/* queueing buffers to camera */
/* see if resolution has changed */
if (ulSize < me->dSTS->size_min ||
ulSize > me->dSTS->size_max)
{
/* report burst rate if we have any */
if (me->debug)
{
if (me->dSTS->dBurst2.n > 0)
{
count_delay(me, "Modified burst shot-to-shot", &me->dSTS->dBurst2, 0);
}
if (me->dSTS->dBurst.n > 0)
{
count_delay(me, "Raw burst shot-to-shot", &me->dSTS->dBurst, -1);
}
}
me->dSTS->dBurst.n = -1;
me->dSTS->dBurst2.n = 0;
/* set new size */
me->dSTS->size_min = ulSize > 2048 ? ulSize - 2048 : 0;
me->dSTS->size_max = ulSize;
/* if more than D1-PAL, we assume it is an image, not a preview */
if (ulSize > 0x119000)
{
/* new burst mode start */
me->dSTS->capturing = 1;
}
else
{
/* preview start */
me->dSTS->capturing = 0;
}
}
}
else if (eModuleAndFlags == (PERF_FlagReceived | PERF_FlagFrame | PERF_ModuleHardware))
{
/* gotten buffers from camera */
if (me->dSTS->capturing &&
ulSize >= me->dSTS->size_min &&
ulSize <= me->dSTS->size_max)
{
/* see if we have a capture already (we ignore the first) to
count into the modified capture */
if (me->dSTS->dBurst.n > 1)
{
/* count last time delta */
if (me->dSTS->dBurst.n > 2)
{
delay_add(&me->dSTS->dBurst2, me->dSTS->last_burst);
delay_add(&me->dSTS->dABurst2, me->dSTS->last_burst);
if (me->debug)
{
fprintf(me->fRt, "rtPERF: [%ld] Modified burst shot-to-shot[0x%lX]: %.3g s\n",
me->dSTS->dBurst2.n, me->dSTS->size_min, 1e-6 * me->dSTS->last_burst);
}
}
me->dSTS->last_burst = TIME_DELTA(perf->time, me->dSTS->dBurst.last_timestamp);
}
else if (me->dSTS->dBurst.n < 0)
{
/* if this is the first shot in the burst sequence */
/* calculate single shot-to-shot delay */
if (me->dSTS->dSingle.n >= 0)
{
if (me->debug)
{
fprintf(me->fRt, "rtPERF: [#%ld] Single shot-to-shot[0x%lX]: %.3g s\n",
me->dSTS->dSingle.n + 1, me->dSTS->size_min, 1e-6 * TIME_DELTA(perf->time, me->dSTS->dSingle.last_timestamp));
}
delay_delta(&me->dSTS->dSingle, perf);
}
}
if (me->dSTS->dBurst.n >= 0)
{
if (me->debug)
{
fprintf(me->fRt, "rtPERF: [#%ld] Raw burst shot-to-shot[0x%lX]: %.3g s\n",
me->dSTS->dBurst.n + 1, me->dSTS->size_min, 1e-6 * TIME_DELTA(perf->time, me->dSTS->dBurst.last_timestamp));
}
delay_add(&me->dSTS->dABurst, TIME_DELTA(perf->time, me->dSTS->dBurst.last_timestamp));
}
delay_delta(&me->dSTS->dBurst, perf);
/* keep last captured image time stamp for single shot-to-shot */
TIME_COPY(me->dSTS->dSingle.last_timestamp, perf->time);
if (me->dSTS->dSingle.n < 0)
{
me->dSTS->dSingle.n = 0; /* captured first time stamp */
}
}
}
}
/* ------------------------ UPTIME METRICS ------------------------ */
if (0 && me->dUptime && me->dUptime->measuring)
{
/* see if we passed our granularity. if yes, calculate uptime */
int steps = TIME_DELTA(perf->time, me->dUptime->last_reporting);
if (steps >= me->granularity)
{
steps /= me->granularity;
double uptime, idletime, load = 0;
/* calculate MHz load */
get_uptime(&uptime, &idletime);
if (uptime > 0 && me->dUptime->success)
{
me->dUptime->last_idletime = idletime - me->dUptime->last_idletime;
me->dUptime->last_uptime = uptime - me->dUptime->last_uptime;
if (me->dUptime->last_uptime > 0)
{
load = 100. * ((me->dUptime->last_uptime - me->dUptime->last_idletime) /
me->dUptime->last_uptime);
me->dUptime->n += steps;
me->dUptime->x += load * steps;
me->dUptime->xx += load * load * steps;
}
}
TIME_INCREASE(me->dUptime->last_reporting, steps * me->granularity);
if (uptime > 0 && me->dUptime->success)
{
me->dUptime->last_uptime = uptime;
me->dUptime->last_idletime = idletime;
if (me->debug)
{
fprintf(me->fRt, "rtPERF: [%ld] ARM CPU-load is %.3g%%\n",
TIME_DELTA(perf->time, me->first_time)/1000000,
load);
}
}
else
{
me->dUptime->success = 0;
}
}
}
}
static xlat_action_t xlat_delay(TALLOC_CTX *ctx, UNUSED fr_cursor_t *out,
REQUEST *request, void const *xlat_inst, UNUSED void *xlat_thread_inst,
fr_value_box_t **in)
{
rlm_delay_t const *inst;
void *instance;
struct timeval resume_at, delay, *yielded_at;
memcpy(&instance, xlat_inst, sizeof(instance)); /* Stupid const issues */
inst = talloc_get_type_abort(instance, rlm_delay_t);
/*
* Record the time that we yielded the request
*/
MEM(yielded_at = talloc(request, struct timeval));
if (gettimeofday(yielded_at, NULL) < 0) {
REDEBUG("Failed getting current time: %s", fr_syserror(errno));
return XLAT_ACTION_FAIL;
}
/*
* If there's no input delay, just yield and
* immediately re-enqueue the request.
* This is very useful for testing.
*/
if (!*in) {
memset(&delay, 0, sizeof(delay));
if (!fr_cond_assert(delay_add(request, &resume_at, yielded_at, &delay, true, true) == 0)) {
return XLAT_ACTION_FAIL;
}
goto yield;
}
if (fr_value_box_list_concat(ctx, *in, in, FR_TYPE_STRING, true) < 0) {
RPEDEBUG("Failed concatenating input");
talloc_free(yielded_at);
return XLAT_ACTION_FAIL;
}
if (fr_timeval_from_str(&delay, (*in)->vb_strvalue) < 0) {
RPEDEBUG("Failed parsing delay time");
talloc_free(yielded_at);
return XLAT_ACTION_FAIL;
}
if (delay_add(request, &resume_at, yielded_at, &delay, inst->force_reschedule, inst->relative) != 0) {
RDEBUG2("Not adding delay");
talloc_free(yielded_at);
return XLAT_ACTION_DONE;
}
yield:
RDEBUG3("Current time %pV, resume time %pV", fr_box_timeval(*yielded_at), fr_box_timeval(resume_at));
if (unlang_xlat_event_timeout_add(request, _delay_done, yielded_at, &resume_at) < 0) {
RPEDEBUG("Adding event failed");
return XLAT_ACTION_FAIL;
}
return unlang_xlat_yield(request, xlat_delay_resume, xlat_delay_cancel, yielded_at);
}
