Почему время таймера timerfd periodi c Linux истекает немного раньше, чем ожидалось? - PullRequest
1 голос
/ 06 марта 2020

Я использую таймер Linux periodi c, в частности, timerfd, срок действия которого я устанавливаю, например, каждые 200 мс.

Однако я заметил, что время таймера истекает, иногда, немного раньше, чем установленное мной время ожидания.

В частности, я использую следующий код C для выполнения простого теста:

#include <stdlib.h>
#include <stdio.h>
#include <time.h>
#include <poll.h>
#include <unistd.h>
#include <inttypes.h>
#include <sys/timerfd.h>
#include <sys/time.h>

#define NO_FLAGS_TIMER 0
#define NUM_TESTS 10

// Function to perform the difference between two struct timeval.
// The operation which is performed is out = out - in
static inline int timevalSub(struct timeval *in, struct timeval *out) {
    time_t original_out_tv_sec=out->tv_sec;

    if (out->tv_usec < in->tv_usec) {
        int nsec = (in->tv_usec - out->tv_usec) / 1000000 + 1;
        in->tv_usec -= 1000000 * nsec;
        in->tv_sec += nsec;
    }

    if (out->tv_usec - in->tv_usec > 1000000) {
        int nsec = (out->tv_usec - in->tv_usec) / 1000000;
        in->tv_usec += 1000000 * nsec;
        in->tv_sec -= nsec;
    }

    out->tv_sec-=in->tv_sec;
    out->tv_usec-=in->tv_usec;

    // '1' is returned when the result is negative
    return original_out_tv_sec < in->tv_sec;
}

// Function to create a timerfd and set it with a periodic timeout of 'time_ms', in milliseconds
int timerCreateAndSet(struct pollfd *timerMon,int *clockFd,uint64_t time_ms) {
    struct itimerspec new_value;
    time_t sec;
    long nanosec;

    // Create monotonic (increasing) timer
    *clockFd=timerfd_create(CLOCK_MONOTONIC,NO_FLAGS_TIMER);
    if(*clockFd==-1) {
        return -1;
    }

    // Convert time, in ms, to seconds and nanoseconds
    sec=(time_t) ((time_ms)/1000);
    nanosec=1000000*time_ms-sec*1000000000;
    new_value.it_value.tv_nsec=nanosec;
    new_value.it_value.tv_sec=sec;
    new_value.it_interval.tv_nsec=nanosec;
    new_value.it_interval.tv_sec=sec;

    // Fill pollfd structure
    timerMon->fd=*clockFd;
    timerMon->revents=0;
    timerMon->events=POLLIN;

    // Start timer
    if(timerfd_settime(*clockFd,NO_FLAGS_TIMER,&new_value,NULL)==-1) {
        close(*clockFd);
        return -2;
    }

    return 0;
}


int main(void) {
    struct timeval tv,tv_prev,tv_curr;
    int clockFd;
    struct pollfd timerMon;
    unsigned long long junk;

    gettimeofday(&tv,NULL);
    timerCreateAndSet(&timerMon,&clockFd,200); // 200 ms periodic expiration time

    tv_prev=tv;

    for(int a=0;a<NUM_TESTS;a++) {
        // No error check on poll() just for the sake of brevity...
        // The final code should contain a check on the return value of poll()
        poll(&timerMon,1,-1);
        (void) read(clockFd,&junk,sizeof(junk));

        gettimeofday(&tv,NULL);
        tv_curr=tv;
        if(timevalSub(&tv_prev,&tv_curr)) {
            fprintf(stdout,"Error! Negative timestamps. The test will be interrupted now.\n");
            break;
        }
        printf("Iteration: %d - curr. timestamp: %lu.%lu - elapsed after %f ms - real est. delta_t %f ms\n",a,tv.tv_sec,tv.tv_usec,200.0,
            (tv_curr.tv_sec*1000000+tv_curr.tv_usec)/1000.0);

        tv_prev=tv;
    }

    return 0;
}

После компиляции с помощью g cc:

gcc -o timertest_stackoverflow timertest_stackoverflow.c

я получаю следующий вывод:

Iteration: 0 - curr. timestamp: 1583491102.833748 - elapsed after 200.000000 ms - real est. delta_t 200.112000 ms
Iteration: 1 - curr. timestamp: 1583491103.33690 - elapsed after 200.000000 ms - real est. delta_t 199.942000 ms
Iteration: 2 - curr. timestamp: 1583491103.233687 - elapsed after 200.000000 ms - real est. delta_t 199.997000 ms
Iteration: 3 - curr. timestamp: 1583491103.433737 - elapsed after 200.000000 ms - real est. delta_t 200.050000 ms
Iteration: 4 - curr. timestamp: 1583491103.633737 - elapsed after 200.000000 ms - real est. delta_t 200.000000 ms
Iteration: 5 - curr. timestamp: 1583491103.833701 - elapsed after 200.000000 ms - real est. delta_t 199.964000 ms
Iteration: 6 - curr. timestamp: 1583491104.33686 - elapsed after 200.000000 ms - real est. delta_t 199.985000 ms
Iteration: 7 - curr. timestamp: 1583491104.233745 - elapsed after 200.000000 ms - real est. delta_t 200.059000 ms
Iteration: 8 - curr. timestamp: 1583491104.433737 - elapsed after 200.000000 ms - real est. delta_t 199.992000 ms
Iteration: 9 - curr. timestamp: 1583491104.633736 - elapsed after 200.000000 ms - real est. delta_t 199.999000 ms

Я ожидаю разницу в реальном времени, оцененную с gettimeofday() , никогда не будет меньше 200 мс (также из-за времени, необходимого для очистки события с read()), но есть также некоторые значения, которые немного меньше 200 мс, например 199.942000 ms.

Знаете ли вы, почему я наблюдаю такое поведение?

Может ли это быть из-за того, что я использую gettimeofday(), а иногда tv_prev берется немного позже (из-за некоторых задержка при вызове read() или gettimeofday() сама по себе) и tv_curr в следующей итерации не составляет, вызывая расчетное время менее 200 мс, в то время как таймер действительно точен в истечении каждые 200 мс?

Заранее большое спасибо.

1 Ответ

0 голосов
/ 06 марта 2020

Это связано с планированием процесса. Таймер действительно очень точный и сигнализирует об истечении времени ожидания каждые 200 мс, но ваша программа не будет регистрировать сигнал, пока не вернет управление. Это означает, что время, которое вы получите от gettimeofday() звонка, может показать более поздний момент в будущем. Вычитая такие задержанные значения, вы можете получить результат, больший или меньший, чем 200 мс.

Как оценить время между фактическим сигналом таймера и вашим вызовом gettimeofday()? Это связано с процессом планирования кванта времени. Этот квант имеет некоторое значение по умолчанию, установленное RR_TIMESLICE в include / linux / sched / rt.h . Вы можете проверить это в своей системе следующим образом:

#include <sched.h>
#include <sys/types.h>
#include <unistd.h>
#include <stdio.h>

int main(void) {
    struct timespec tp;
    if (sched_rr_get_interval(getpid(), &tp)) {
      perror("Cannot get scheduler quantum");
    } else {
      printf("Scheduler quantum is %f ms\n", (tp.tv_sec * 1e9 + tp.tv_nsec) / 1e6); 
    }
}

Вывод в моей системе:

Scheduler quantum is 4.000000 ms

Итак, вам, возможно, придется дождаться завершения кванта планировщика другого процесса sh, прежде чем вы получите контроль и сможете прочитать текущее время. В моей системе это может привести к отклонению результирующей задержки примерно на ± 4 мс от ожидаемых 200 мс. После выполнения почти 7000 итераций я получаю следующее распределение зарегистрированных времен ожидания:

Distribution of waiting times

Как вы можете видеть, большая часть времени лежит в интервал ± 2 мс вокруг ожидаемых 200 мс. Минимальное и максимальное время среди всех итераций составило 189,992 мс и 210,227 мс соответственно:

~$ sort times.txt | head
189.992000
190.092000
190.720000
194.402000
195.250000
195.746000
195.847000
195.964000
196.256000
196.420000
~$ sort times.txt | tail
203.746000
203.824000
203.900000
204.026000
204.273000
205.625000
205.634000
208.974000
210.202000
210.227000
~$

Отклонения, превышающие 4 мс, вызваны редкими ситуациями, когда программе нужно было ждать несколько квантов, а не только одного.

...