-
Notifications
You must be signed in to change notification settings - Fork 939
Description
Steps to reproduce:
- clone latest code from github, build and install
- compile and run the attached code
Explanation of issue being shown: Very first log value is from me being lazy in the sample code, logs after that are during boot, multiple callouts get delayed and batched so they are very close to each other. something to do with freebsd.expire being too far ahead for first trigger, increasing boot.hz seems to decrease the delay but besides the point that's a small issue.
Next logs show that if callout is registered via EVFILT_TIMER very close to boot time, it is able to trigger every 1 second.
After it updates/adds a timer further away from boot, however, it deviates a lot.
It also for some reason has its units way off - I had to ask it to interpret my argument as 1 nanosecond(s) for it to track 1 second.
Expected behavior: to track time properly regardless of when callout is added, and to correctly interpret the units specified.
I tried to debug a bit, but could not figure out a solution - seems like maybe something to do with sbinuptime() and tick_sbt not matching. I am unsure if this bug is limited to EVFILT_TIMER or how many other subsystems are affected, clearly it can track time under some circumstances.
ADD/UPDATE TIMER
TRIGGER ident=1000000 data=1 fflags=0 since_last=45185.574288
TRIGGER ident=1000000 data=1 fflags=0 since_last=0.032788
TRIGGER ident=1000000 data=1 fflags=0 since_last=0.033428
TRIGGER ident=1000000 data=1 fflags=0 since_last=0.033980
TRIGGER ident=1000000 data=1 fflags=0 since_last=0.091014
TRIGGER ident=1000000 data=1 fflags=0 since_last=0.999392
TRIGGER ident=1000000 data=1 fflags=0 since_last=0.999392
TRIGGER ident=1000000 data=1 fflags=0 since_last=0.999391
TRIGGER ident=1000000 data=1 fflags=0 since_last=0.999392
TRIGGER ident=1000000 data=1 fflags=0 since_last=0.999391
ADD/UPDATE TIMER
TRIGGER ident=1000000 data=1 fflags=0 since_last=6.219578
TRIGGER ident=1000000 data=1 fflags=0 since_last=6.219578
TRIGGER ident=1000000 data=1 fflags=0 since_last=6.219578
TRIGGER ident=1000000 data=1 fflags=0 since_last=6.219579
TRIGGER ident=1000000 data=1 fflags=0 since_last=6.219578
TRIGGER ident=1000000 data=1 fflags=0 since_last=6.219577
TRIGGER ident=1000000 data=1 fflags=0 since_last=6.219586
TRIGGER ident=1000000 data=1 fflags=0 since_last=6.219569
TRIGGER ident=1000000 data=1 fflags=0 since_last=6.219578
TRIGGER ident=1000000 data=1 fflags=0 since_last=6.219579
ADD/UPDATE TIMER
TRIGGER ident=1000000 data=1 fflags=0 since_last=68.416336
TRIGGER ident=1000000 data=1 fflags=0 since_last=68.416337
TRIGGER ident=1000000 data=1 fflags=0 since_last=68.416335
...
#include <bits/time.h>
#include <errno.h>
#include <ff_api.h>
#include <generic/rte_cycles.h>
#include <stdio.h>
#include <string.h>
#include <time.h>
#include <unistd.h>
#define MAX_EVENTS 8 /* max events to return on a kevent() call */
static struct kevent events[MAX_EVENTS];
static int kq;
double get_ns() {
struct timespec ts;
clock_gettime(CLOCK_MONOTONIC, &ts);
return 1e9L * ts.tv_sec + ts.tv_nsec;
}
static void add_or_update_timer() {
printf("ADD/UPDATE TIMER\n");
struct kevent kev;
EV_SET(&kev, 1000000, EVFILT_TIMER, EV_ADD, NOTE_NSECONDS, 1, NULL);
if (ff_kevent(kq, &kev, 1, NULL, 0, NULL) == -1) {
printf("ff_kevent error:%d, %s\n", errno, strerror(errno));
}
}
static int loop(void __attribute((unused)) * arg) {
static uint32_t ntrigs = 0;
static double last_ns = 0;
int nevents = ff_kevent(kq, NULL, 0, events, MAX_EVENTS, NULL);
if (nevents == -1) {
perror("loop::ff_kevent()");
return 0;
}
for (int i = 0; i < nevents; i++) {
struct kevent event = events[i];
if (event.filter == EVFILT_TIMER) {
double ns = get_ns();
printf("TRIGGER ident=%lu data=%ld fflags=%d since_last=%f\n", event.ident,
event.data, event.fflags, (ns - last_ns) / NS_PER_S);
last_ns = ns;
if (++ntrigs == 10) {
add_or_update_timer();
ntrigs = 0;
}
}
}
return 0;
}
int main(int argc, char *argv[]) {
if (ff_init(argc, argv) != 0) {
fprintf(stderr, "Failed to ff_init(%d): %s\n", errno, strerror(errno));
return 1;
}
kq = ff_kqueue();
if (kq == -1) {
fprintf(stderr, "Failed to kqueue(%d): %s\n", errno, strerror(errno));
return 0;
}
add_or_update_timer();
ff_run(loop, NULL);
return 1;
}