Надежность ядра Linux add_timer при разрешении в один миг?

В приведенном ниже коде есть простой модуль ядра Linux (драйвер), который вызывает функцию многократно 10 раз, используя add_timer с разрешением 1 минута (то есть таймер запланирован на jiffies + 1). С использованием bash скрипт rerun.sh тогда я получу метки времени из распечатки в syslog и визуализировать их, используя gnuplot,

В большинстве случаев я получаю syslog вывод, как это:

[ 7103.055787] Init testjiffy: 0 ; HZ: 250 ; 1/HZ (ms): 4
[ 7103.056044]  testjiffy_timer_function: runcount 1 
[ 7103.060045]  testjiffy_timer_function: runcount 2 
[ 7103.064052]  testjiffy_timer_function: runcount 3 
[ 7103.068050]  testjiffy_timer_function: runcount 4 
[ 7103.072053]  testjiffy_timer_function: runcount 5 
[ 7103.076036]  testjiffy_timer_function: runcount 6 
[ 7103.080044]  testjiffy_timer_function: runcount 7 
[ 7103.084044]  testjiffy_timer_function: runcount 8 
[ 7103.088060]  testjiffy_timer_function: runcount 9 
[ 7103.092059]  testjiffy_timer_function: runcount 10 
[ 7104.095429] Exit testjiffy

... что приводит к временным рядам и графикам дельта-гистограммы, таким как:

testjiffy_00001.png

По сути, это качество синхронизации, которое я ожидаю от кода.

Тем не менее, время от времени я получаю снимок вроде:

[ 7121.377507] Init testjiffy: 0 ; HZ: 250 ; 1/HZ (ms): 4
[ 7121.380049]  testjiffy_timer_function: runcount 1 
[ 7121.384062]  testjiffy_timer_function: runcount 2 
[ 7121.392053]  testjiffy_timer_function: runcount 3 
[ 7121.396055]  testjiffy_timer_function: runcount 4 
[ 7121.400068]  testjiffy_timer_function: runcount 5 
[ 7121.404085]  testjiffy_timer_function: runcount 6 
[ 7121.408084]  testjiffy_timer_function: runcount 7 
[ 7121.412072]  testjiffy_timer_function: runcount 8 
[ 7121.416083]  testjiffy_timer_function: runcount 9 
[ 7121.420066]  testjiffy_timer_function: runcount 10 
[ 7122.417325] Exit testjiffy

... что приводит к рендерингу вроде:

testjiffy_00002.png

... и я как: "WHOOOOOAAAAAA ... подождите секунду..." - разве импульс не упал из последовательности? Означающий, что add_timer пропустил слот, а затем запустил функцию в следующем 4 мс слоте?

Интересно то, что при выполнении этих тестов у меня не запускается ничего, кроме терминала, веб-браузера и текстового редактора - поэтому я не вижу ничего работающего, что может привести к зависанию ОС / ядра; и, таким образом, я действительно не вижу причины, по которой ядро может совершить такой большой промах (за весь период). Когда я прочитал о синхронизации ядра Linux, например, " Самый простой и наименее точный из всех таймеров... это API таймера ", я прочитал это "наименее точное" как: "не ожидайте точно 4 мс периода" (согласно этому пример) - а я нет, я в порядке с дисперсией, показанной на (первой) гистограмме; но я не ожидаю, что весь период будет пропущен!?

Итак, мой вопрос (ы):

  • Это ожидаемое поведение от add_timer в этом разрешении (что период может быть иногда пропущен)?
  • Если это так, есть ли способ "заставить" add_timer запустить функцию в каждом слоте 4 мс, как указано в jiffy на этой платформе?
  • Возможно ли, что я получаю "неправильную" временную метку - например, временную метку, отражающую, когда произошла фактическая "печать" в системном журнале, а не когда функция фактически сработала?
  • Обратите внимание, что я не ищу разрешение периода ниже того, что соответствует краткости (в данном случае, 4 мс); и при этом я не пытаюсь уменьшить дельта-дисперсию, когда код работает должным образом. Так что, на мой взгляд, у меня нет ни требований "таймера высокого разрешения", ни требований "жесткого реального времени" - я просто хочу add_timer стрелять надежно. Возможно ли это на этой платформе, не прибегая к специальным конфигурациям ядра в режиме реального времени?

Бонусный вопрос: в rerun.sh ниже вы заметите два sleep с помечены MUSTHAVE ; если какой-либо из них пропущен / прокомментирован, ОС / ядро зависает и требует полной перезагрузки. И я не могу понять, почему - действительно ли возможно, что бег rmmod после insmod из bash настолько быстро, что это будет конфликтовать с нормальным процессом загрузки / выгрузки модуля?

Информация о платформе:

$ cat /proc/cpuinfo | grep "processor\|model name\|MHz\|cores"
processor   : 0       # (same for 1)
model name  : Intel(R) Atom(TM) CPU N450   @ 1.66GHz
cpu MHz             : 1000.000
cpu cores   : 1
$ echo $(cat /etc/issue ; uname -a)
Ubuntu 11.04 \n \l Linux mypc 2.6.38-16-generic #67-Ubuntu SMP Thu Sep 6 18:00:43 UTC 2012 i686 i686 i386 GNU/Linux
$ echo $(lsb_release -a 2>/dev/null | tr '\n' ' ')
Distributor ID: Ubuntu Description: Ubuntu 11.04 Release: 11.04 Codename: natty

Код:

$ cd /tmp/testjiffy
$ ls
Makefile  rerun.sh  testjiffy.c

Makefile:

obj-m += testjiffy.o

all:
    make -C /lib/modules/$(shell uname -r)/build M=$(PWD) modules

clean:
    make -C /lib/modules/$(shell uname -r)/build M=$(PWD) clean

testjiffy.c:

/*
 *  [http://www.tldp.org/LDP/lkmpg/2.6/html/lkmpg.html#AEN189 The Linux Kernel Module Programming Guide]
 */


#include <linux/module.h>   /* Needed by all modules */
#include <linux/kernel.h>   /* Needed for KERN_INFO */
#include <linux/init.h>     /* Needed for the macros */
#include <linux/jiffies.h>
#include <linux/time.h>
#define MAXRUNS 10

static volatile int runcount = 0;
static struct timer_list my_timer;

static void testjiffy_timer_function(unsigned long data)
{
  int tdelay = 100;

  runcount++;
  if (runcount == 5) {
    while (tdelay > 0) { tdelay--; } // small delay
  }

  printk(KERN_INFO
    " %s: runcount %d \n",
    __func__, runcount);

  if (runcount < MAXRUNS) {
    my_timer.expires = jiffies + 1;
    add_timer(&my_timer);
  }
}


static int __init testjiffy_init(void)
{
    printk(KERN_INFO
    "Init testjiffy: %d ; HZ: %d ; 1/HZ (ms): %d\n",
               runcount,      HZ,        1000/HZ);

  init_timer(&my_timer);

    my_timer.function = testjiffy_timer_function;
    //my_timer.data = (unsigned long) runcount;

  my_timer.expires = jiffies + 1;
    add_timer(&my_timer);
    return 0;
}

static void __exit testjiffy_exit(void)
{
    printk(KERN_INFO "Exit testjiffy\n");
}

module_init(testjiffy_init);
module_exit(testjiffy_exit);

MODULE_LICENSE("GPL");

rerun.sh:

#!/usr/bin/env bash

set -x
make clean
make
# blank syslog first
sudo bash -c 'echo "0" > /var/log/syslog'
sleep 1   # MUSTHAVE 01!
# reload kernel module/driver
sudo insmod ./testjiffy.ko
sleep 1   # MUSTHAVE 02!
sudo rmmod testjiffy
set +x

# copy & process syslog

max=0;
for ix in _testjiffy_*.syslog; do
  aa=${ix#_testjiffy_};
  ab=${aa%.syslog} ;
  case $ab in
    *[!0-9]*) ab=0;;          # reset if non-digit obtained; else
    *) ab=$(echo $ab | bc);;  # remove leading zeroes (else octal)
  esac
  if (( $ab > $max )) ; then
    max=$((ab));
  fi;
done;
newm=$( printf "%05d" $(($max+1)) );
PLPROC='chomp $_;
if (!$p) {$p=0;}; if (!$f) {$f=$_;} else {
  $a=$_-$f; $d=$a-$p;
  print "$a $d\n" ; $p=$a;
};'

set -x
grep "testjiffy" /var/log/syslog | cut -d' ' -f7- > _testjiffy_${newm}.syslog
grep "testjiffy_timer_function" _testjiffy_${newm}.syslog \
  | sed 's/\[\(.*\)\].*/\1/' \
  | perl -ne "$PLPROC" \
  > _testjiffy_${newm}.dat
set +x

cat > _testjiffy_${newm}.gp <<EOF
set terminal pngcairo font 'Arial,10' size 900,500
set output '_testjiffy_${newm}.png'
set style line 1 linetype 1 linewidth 3 pointtype 3 linecolor rgb "red"
set multiplot layout 1,2 title "_testjiffy_${newm}.syslog"
set xtics rotate by -45
set title "Time positions"
set yrange [0:1.5]
set offsets graph 50e-3, 1e-3, 0, 0
plot '_testjiffy_${newm}.dat' using 1:(1.0):xtic(gprintf("%.3se%S",\$1)) notitle with points ls 1, '_testjiffy_${newm}.dat' using 1:(1.0) with impulses ls 1
binwidth=0.05e-3
set boxwidth binwidth
bin(x,width)=width*floor(x/width) + width/2.0
set title "Delta diff histogram"
set style fill solid 0.5
set autoscale xy
set offsets graph 0.1e-3, 0.1e-3, 0.1, 0.1
plot '_testjiffy_${newm}.dat' using (bin(\$2,binwidth)):(1.0) smooth freq with boxes ls 1
unset multiplot
EOF
set -x; gnuplot _testjiffy_${newm}.gp ; set +x

РЕДАКТИРОВАТЬ: мотивировано этим комментарием @granquet, я пытался получить статистику планировщика из /proc/schedstat а также /proc/sched_debug, используя dd через call_usermodehelper; обратите внимание, что это большую часть времени "пропускает" (то есть файл из-за 7-го, или 6-го, или X-го запуска функции будет отсутствовать); но мне удалось получить два полных прогона и опубликовать их по https://gist.github.com/anonymous/5709699 (как я заметил, gist может быть предпочтительнее, чем pastebin на SO), учитывая, что вывод довольно большой; *_11* файлы журнала правильного запуска, *_17* файлы регистрируют прогон с "дропом".

Обратите внимание, я также перешел на mod_timer_pinned в модуле, и это не сильно помогает (логи гистограммы получены с помощью модуля, использующего эту функцию). Это изменения в testjiffy.c:

#include <linux/kmod.h> // usermode-helper API
...
char fcmd[] = "of=/tmp/testjiffy_sched00";
char *dd1argv[] = { "/bin/dd", "if=/proc/schedstat", "oflag=append", "conv=notrunc", &fcmd[0], NULL };
char *dd2argv[] = { "/bin/dd", "if=/proc/sched_debug", "oflag=append", "conv=notrunc", &fcmd[0], NULL };
static char *envp[] = {
      "HOME=/",
      "TERM=linux",
      "PATH=/sbin:/bin:/usr/sbin:/usr/bin", NULL };

static void testjiffy_timer_function(unsigned long data)
{
  int tdelay = 100;
  unsigned long tjnow;

  runcount++;
  if (runcount == 5) {
    while (tdelay > 0) { tdelay--; } // small delay
  }

  printk(KERN_INFO
    " %s: runcount %d \n",
    __func__, runcount);

  if (runcount < MAXRUNS) {
    mod_timer_pinned(&my_timer, jiffies + 1);
    tjnow = jiffies;
    printk(KERN_INFO
      " testjiffy expires: %lu - jiffies %lu => %lu / %lu\n",
      my_timer.expires, tjnow, my_timer.expires-tjnow, jiffies);
    sprintf(fcmd, "of=/tmp/testjiffy_sched%02d", runcount);
    call_usermodehelper( dd1argv[0], dd1argv, envp, UMH_NO_WAIT );
    call_usermodehelper( dd2argv[0], dd2argv, envp, UMH_NO_WAIT );
  }
}

... и это в rerun.sh:

...
set +x

for ix in /tmp/testjiffy_sched*; do
  echo $ix | tee -a _testjiffy_${newm}.sched
  cat $ix >> _testjiffy_${newm}.sched
done
set -x ; sudo rm /tmp/testjiffy_sched* ; set +x

cat > _testjiffy_${newm}.gp <<EOF
...

Я буду использовать этот пост для подробного ответа.

@CL.: большое спасибо за ответ. Хорошо, что он подтвердил, что "возможно, что ваша функция таймера будет вызвана позже"; Зарегистрировав jiffies, я также понял, что функция таймера вызывается позднее, и, кроме того, она сама по себе не делает ничего "неправильного".

Полезно знать о временных метках; Интересно, возможно ли это: функция таймера срабатывает в нужное время, но ядро ​​вытесняет службу ведения журнала ядра (полагаю, klogd), так я получу отсроченную метку времени? Тем не менее, я пытаюсь создать "зацикленную" (или, скорее, периодическую) функцию таймера для записи на аппаратное обеспечение, и я впервые заметил это "падение", осознав, что ПК не записывает данные через определенные интервалы на шине USB; и учитывая, что временные метки подтверждают это поведение, это, вероятно, не проблема здесь (я думаю).

Я изменил функцию таймера, чтобы она срабатывает относительно запланированного времени последнего таймера (my_timer.expires) - снова через mod_timer_pinned вместо add_timer:

static void testjiffy_timer_function(unsigned long data)
{
  int tdelay = 100;
  unsigned long tjlast;
  unsigned long tjnow;

  runcount++;
  if (runcount == 5) {
    while (tdelay > 0) { tdelay--; } // small delay
  }

  printk(KERN_INFO
    " %s: runcount %d \n",
    __func__, runcount);

  if (runcount < MAXRUNS) {
    tjlast = my_timer.expires;
    mod_timer_pinned(&my_timer, tjlast + 1);
    tjnow = jiffies;
    printk(KERN_INFO
      " testjiffy expires: %lu - jiffies %lu => %lu / %lu last: %lu\n",
      my_timer.expires, tjnow, my_timer.expires-tjnow, jiffies, tjlast);
  }
}

... и первые несколько попыток, это работает безупречно - однако, в конце концов, я получаю это:

[13389.775508] Init testjiffy: 0 ; HZ: 250 ; 1/HZ (ms): 4
[13389.776051]  testjiffy_timer_function: runcount 1 
[13389.776063]  testjiffy expires: 3272445 - jiffies 3272444 => 1 / 3272444 last: 3272444
[13389.780053]  testjiffy_timer_function: runcount 2 
[13389.780068]  testjiffy expires: 3272446 - jiffies 3272445 => 1 / 3272445 last: 3272445
[13389.788054]  testjiffy_timer_function: runcount 3 
[13389.788073]  testjiffy expires: 3272447 - jiffies 3272447 => 0 / 3272447 last: 3272446
[13389.788090]  testjiffy_timer_function: runcount 4 
[13389.788096]  testjiffy expires: 3272448 - jiffies 3272447 => 1 / 3272447 last: 3272447
[13389.792070]  testjiffy_timer_function: runcount 5 
[13389.792091]  testjiffy expires: 3272449 - jiffies 3272448 => 1 / 3272448 last: 3272448
[13389.796044]  testjiffy_timer_function: runcount 6 
[13389.796062]  testjiffy expires: 3272450 - jiffies 3272449 => 1 / 3272449 last: 3272449
[13389.800053]  testjiffy_timer_function: runcount 7 
[13389.800063]  testjiffy expires: 3272451 - jiffies 3272450 => 1 / 3272450 last: 3272450
[13389.804056]  testjiffy_timer_function: runcount 8 
[13389.804072]  testjiffy expires: 3272452 - jiffies 3272451 => 1 / 3272451 last: 3272451
[13389.808045]  testjiffy_timer_function: runcount 9 
[13389.808057]  testjiffy expires: 3272453 - jiffies 3272452 => 1 / 3272452 last: 3272452
[13389.812054]  testjiffy_timer_function: runcount 10 
[13390.815415] Exit testjiffy

... который выглядит так:

testjiffy_00027

... так, в основном, у меня есть задержка / "падение" в слоте +8 мс (который должен быть @3272446 jiffies), а затем две функции выполняются в слоте +12 мс (который будет @ 3272447 jiffies); из-за этого вы даже можете увидеть надпись на графике как "более жирную". Это лучше, в том смысле, что последовательность "отбрасывания" теперь синхронна с правильной последовательностью без отбрасывания (как вы сказали: "чтобы избежать того, что одна поздняя функция таймера сдвигает все последующие вызовы таймера") - однако я все еще пропустить удар; и так как мне приходится записывать байты в аппаратное обеспечение при каждом ударе, поэтому я сохраняю постоянную и постоянную скорость передачи, это, к сожалению, мало помогает мне.

Что касается другого предложения, "использовать десять таймеров" - из-за моей конечной цели (запись на аппаратное обеспечение с использованием периодической функции таймера lo-res); Сначала я подумал, что это не применимо - но если больше ничего не возможно (кроме как делать некоторые специальные приготовления ядра в реальном времени), то я непременно попробую схему, в которой у меня есть 10 (или N) таймеров (возможно, хранящихся в массив), которые запускаются периодически один за другим.

РЕДАКТИРОВАТЬ: просто добавив оставшиеся соответствующие комментарии:

Передачи USB либо запланированы заранее (изохронно), либо не имеют гарантий синхронизации (асинхронно). Если ваше устройство не использует изохронную передачу, оно плохо спроектировано. - кл. 5 июня в 10:47

Спасибо за комментарий, @CL. - "... запланировано заранее (изохронно)..." избавило меня от путаницы. Я (в конечном счете) нацеливаюсь на FT232, который имеет только режим BULK - и пока байты на такт таймера низки, я могу фактически "обмануть" свой путь в "потоковой передаче" данных с помощью add_timer; однако, когда я передаю количество байтов, близкое к потреблению полосы пропускания, эти "пропуски зажигания" начинают становиться заметными в виде падений. Таким образом, я был заинтересован в тестировании пределов того, для чего мне нужна надежно повторяющаяся функция "таймера" - есть ли что-нибудь еще, что я мог бы попытаться получить надежным "таймером"? - 5 июня в 12:27

Массовые переводы @sdaau не подходят для потоковой передачи. Вы не можете исправить недостатки в аппаратном протоколе, используя другой вид программного таймера. - кл. 5 июня в 13:50

... и как мой ответ на @CL. Я знаю, что не смогу исправить недостатки; Я был более заинтересован в наблюдении за этими недостатками - скажем, если функция ядра выполняет периодическую USB-запись, я мог бы наблюдать сигналы на области / анализаторе и, надеюсь, увидеть, в каком смысле режим массовой памяти не подходит. Но сначала я должен был бы верить, что функция может (хотя бы в некоторой степени) надежно повторяться с периодической частотой (то есть "генерировать" такт / такт) - и до сих пор я не знала, что не могу доверять add_timer в разрешении jiffies (поскольку он способен относительно легко пропустить весь период). Тем не менее, похоже, что переход на Linux с таймерами высокого разрешения (hrtimer) действительно дает мне надежную периодическую функцию в этом смысле - так что я думаю, что это решает мою проблему (опубликовано в моем ответе ниже).

Источник

2 ответа

Решение

Большое спасибо за все комментарии и ответы; все они указывали на вещи, которые должны быть приняты во внимание - но, учитывая, что я отчасти вечный нуб, мне все же нужно было еще немного почитать, прежде чем получить некоторое понимание (надеюсь, правильное). Кроме того, я не мог найти что-то конкретное для периодически "тикающих" функций - поэтому я выложу более подробный ответ здесь.

Короче говоря - для надежной периодической функции ядра Linux при разрешении в один миг не используйте add_timer (<linux/time.h>), так как это может "уронить" весь период; использовать таймеры высокого разрешения (<linux/hrtimer.h>) вместо Более подробно:

Возможно ли, что я получаю "неправильную" метку времени -...?

@CL.: Отметка времени в журнале - это время, когда эта строка была напечатана в журнале.

Так что, возможно, это возможно - но, оказывается, проблема не в этом:

Является ли это ожидаемым поведением add_timer в этом разрешении (что период иногда может быть пропущен)?

Я думаю, получается - да

Если да, есть ли способ "заставить" add_timer запускать функцию в каждом слоте 4 мс, как указано в jiffy на этой платформе?

... и (я думаю, снова), получается - нет.

Теперь причины этого несколько неуловимы - и я надеюсь, что если я не понял их правильно, кто-то меня поправит. Во-первых, первое заблуждение, которое у меня возникло, было то, что "часы - это просто часы" (в смысле: даже если они реализованы в виде компьютерного кода) - но это не совсем правильно. Ядро, по сути, должно где-то "ставить в очередь" "событие", каждый раз что-то вроде add_timer используется; и этот запрос может исходить от чего бы то ни было: от любого (и всех) сортов драйверов или даже, возможно, от пространства пользователя.

Проблема в том, что такая "постановка в очередь" стоит - поскольку в дополнение к тому, что ядру приходится обрабатывать (эквивалентно) обход и вставку (и удаление) элементов в массиве, оно также должно обрабатывать задержки по таймеру, охватывающие несколько порядков (от скажем, миллисекунды, может быть, 10 секунд); и тот факт, что некоторые драйверы (как, по-видимому, драйверы для сетевых протоколов), по-видимому, ставят в очередь много событий таймера, которые обычно отменяются перед запуском - в то время как другие типы могут требовать совершенно другого поведения (как в моем случае) в периодической функции вы ожидаете, что в большинстве случаев событие обычно не отменяется, и вы также ставите события в очередь по очереди). Кроме того, ядро ​​должно справиться с этим для однопроцессорных или SMP против многопроцессорных платформ. Таким образом, при реализации обработки таймера в ядре существует компромисс между затратами и выгодой.

Оказывается, архитектура вокруг jiffies/ add_timer предназначен для работы с наиболее распространенными устройствами - и для них точность при быстром разрешении не является проблемой; но это также означает, что с помощью этого метода нельзя ожидать надежного таймера при разрешении в один миг. Это также усугубляется тем фактом, что ядро ​​обрабатывает эти "очереди событий", рассматривая их (в некоторой степени) как запросы на обслуживание прерываний (IRQ); и что в ядре есть несколько уровней приоритета при обработке IRQ, где подпрограмма с более высоким приоритетом может опередить низкоприоритетную (то есть: прервать и приостановить подпрограмму с более низким приоритетом, даже если она выполняется во время - и позволить рутине с более высоким приоритетом заниматься своими делами). Или, как уже отмечалось ранее:

@granquet: таймеры работают в контексте мягкого irq, что означает, что они имеют наивысший приоритет и выгружают все, что работает / работает на ЦП... но аппаратные прерывания, которые не отключаются при обслуживании мягкого irq. Таким образом, вы можете (наиболее вероятное объяснение) получить аппаратное прерывание здесь и там, которое прерывает ваш таймер... и, таким образом, вы получите прерывание, которое не обслуживается в нужное время.

@CL.: Действительно возможно, что ваша функция таймера будет вызвана позже, чем истекает то, что установлено. Возможные причины: задержки в планировании, другие драйверы, которые слишком долго отключают прерывания (графические драйверы и драйверы WLAN являются обычными виновниками), или какой-то дурацкий BIOS, выполняющий код SMI.

Теперь я тоже так думаю - думаю, это может быть иллюстрацией того, что происходит:

  • jiffies изменяется, скажем, до 10000 (== 40000 мс при 250 Гц)
  • Скажем, функция таймера, (в очереди add_timer) собирается начать работать - но еще не начал работать
  • Скажем, здесь сетевая карта генерирует (по какой-либо причине) аппаратное прерывание
  • Аппаратное прерывание, имеющее более высокий приоритет, запускает ядро, чтобы предвосхитить (остановить и приостановить) функцию таймера (возможно, запущенную сейчас, и только несколько инструкций в ней);
  • Это означает, что ядро ​​теперь должно перепланировать функцию таймера, чтобы она выполнялась на более позднем этапе - и поскольку каждый работает только с целочисленными операциями в ядре, а разрешение по времени для такого рода событий находится в затруднительном положении - лучшее, что он может сделать, это перепланировать это для jiffies+1 (10001 == 40004 мс при 250 Гц)
  • Теперь ядро ​​переключает контекст на процедуру обслуживания IRQ драйвера сетевой карты, и это делает свое дело
  • Допустим, процедура IRQ завершается за 200 мкс - это означает, что теперь мы (в "абсолютных" терминах) на 40000,2 мс - однако мы также все еще на 10000 пробежек
  • Если бы ядро ​​теперь переключило контекст обратно на функцию таймера, оно бы завершилось - без необходимости обязательно замечать задержку;
  • ... однако этого не произойдет, потому что функция таймера запланирована на следующее мгновение!
  • Таким образом, ядро ​​работает (возможно, спит) в течение следующих 3,8 мс
  • jiffies изменяется на 10001 (== 40004 мс при 250 Гц)
  • (ранее перенесено) функция таймера работает - и это время завершается без перерыва

На самом деле я не провел подробный анализ, чтобы увидеть, является ли последовательность событий в точности такой, как описано выше; но я вполне убежден, что это что-то близкое - иными словами, проблема разрешения - тем более что подход таймера с высоким разрешением, похоже, не демонстрирует такое поведение. Было бы здорово получить журнал планировщика и точно знать , что случилось с упреждением, но я сомневаюсь, что обратный путь к пользовательскому пространству, который я попытался в OP edit, в ответ на комментарий @granquet, это правильная вещь.

В любом случае, возвращаясь к этому:

Обратите внимание, что я не ищу разрешение периода ниже того, что соответствует краткости (в данном случае, 4 мс); и при этом я не пытаюсь уменьшить дельта-дисперсию, когда код работает должным образом. Так что, на мой взгляд, у меня нет ни требований "таймера высокого разрешения", ни требований "жесткого реального времени"...

... здесь я допустил грубую ошибку - как показывает приведенный выше анализ, у меня действительно были требования "высокого разрешения"! И если бы я понял, что раньше, я мог бы найти соответствующее чтение раньше. В любом случае, некоторые соответствующие документы - даже если они не обсуждают конкретно периодические функции - были для меня:

  • LDD3: 5.3. Семафоры и мьютексы - (в описании драйвера с различными требованиями отсюда): " не будет доступа к обработчикам прерываний или другим асинхронным контекстам. Особых требований к задержке (времени отклика) нет; программисты приложений понимают, что запросы ввода-вывода обычно не устраивает сразу
  • https://www.kernel.org/doc/Documentation/timers/hrtimers.txt - " Код timers.c очень" жестко закодирован "в отношении допусков и 32-битных допущений и отточен и микрооптимизирован для относительно узкого варианта использования (перепады в относительно узком диапазоне HZ") в течение многих лет - и, таким образом, даже небольшие расширения его легко сломать концепцию колеса "
  • Т. Глейкснер, Д. Нихаус Хртимерс и далее: трансформация подсистем времени Linux (pdf) - (наиболее подробно см. Также диаграммы внутри) " Каскадное колесо таймера (CTW), которое было реализовано в 1997 году, заменило оригинальное упорядоченное по времени двойное связанный список для решения проблемы масштабируемости времени вставки O(N) в связанный список... Текущий подход к управлению таймерами в Linux хорошо справляется с удовлетворением чрезвычайно широкого диапазона требований, но не может обеспечить требуемое качество обслуживания в некоторых случаях именно потому, что он должен удовлетворять такому широкому диапазону требований... Таймеры, связанные с тайм-аутом, хранятся в существующем колесе таймера, и была реализована новая подсистема, оптимизированная для требований к таймеру (с высоким разрешением) hrtimers. время (единицы: наносекунды)... Они хранятся в отсортированном по времени списке для каждого процессора, реализованном в виде красно-черного дерева ".
  • API таймера высокого разрешения [LWN.net] - " По своей сути механизм hrtimer остается тем же. Вместо того чтобы использовать структуру данных" колесо таймера ", hrtimers живут в отсортированном по времени связанном списке со следующим таймером для срок действия истекает во главе списка. Отдельное красное / черное дерево также используется для включения и удаления событий таймера без сканирования по списку. Но хотя ядро ​​остается тем же, почти все остальное изменилось, по крайней мере внешне. "
  • Программные прерывания и в реальном времени [LWN.net] - " Механизм soft irq предназначен для обработки обработки, которая почти - но не совсем - так же важна, как обработка аппаратных прерываний. Softirq работает с высоким приоритетом (хотя с интересным исключением, описанным ниже), но с включенными аппаратными прерываниями. Таким образом, они обычно будут выгружать любую работу, кроме ответа на "реальное" аппаратное прерывание... Однако, начиная с набора исправлений реального времени 3.0, эта возможность исчезла... В ответ, в 3.6.1-rt1, обработка softirqs снова изменилась. "
  • Таймауты с высоким (но не слишком высоким) разрешением [LWN.net] - "_poll () и epoll_wait() занимают целое число миллисекунд; select() принимает структурный временной интервал с микросекундным разрешением, а ppoll() и pselect() принять структурную временную спецификацию с разрешением наносекунды. Тем не менее, они все одинаковые в том, что они преобразуют это значение тайм-аута в jiffies, с максимальным разрешением от одной до десяти миллисекунд. Программист может запрограммировать вызов pselect() с 10 наносекундами тайм-аут, но вызов может не вернуться до 10 миллисекунд спустя, даже при отсутствии конкуренции за процессор... Это полезная функция, но она происходит за счет некоторых существенных изменений API._"

Из кавычек ясно, что средства синхронизации с высоким разрешением все еще находятся в активной разработке (с изменениями API) в ядре - и я боялся, что, возможно, мне придется установить специальное ядро ​​"в реальном времени", К счастью, в моем ядре 2.6.38-16 SMP, по-видимому, доступны (и работают) таймеры высокого разрешения без каких-либо особых изменений. Ниже приведен список измененных testjiffies.c модуль ядра, который теперь использует таймеры высокого разрешения, но в остальном сохраняет тот же период, который определен jiffies, Для тестирования я сделал цикл 200 раз (вместо 10 в ОП); и работает rerun.sh сценарий примерно 20-30 раз, это худший результат, который я получил:

testjiffy_00037.png

Временная последовательность теперь явно нечитаема, но гистограмма все еще может сказать нам это: принимая 0,00435–0,004 (= 0,004–0,00365) = 350 мкс для максимального отклонения, это составляет только 100*(350/4000) = 8,75% от ожидаемый период; с которым у меня, конечно, нет проблем. Кроме того, я никогда не получал ни капли (или, соответственно, всего 2* периода = 8 мс задержки), ни задержки 0 мс - полученные мною захваты в остальном имеют качество, показанное на первом изображении в OP. Теперь, конечно, я мог бы провести более длительный тест и более точно увидеть, насколько он надежен - но это вся надежность, которую я ожидал / должен увидеть в этом простом случае; Сравните это с ОП, где я получу падение всего за 10 циклов, с вероятностью бросить монету - каждую секунду или третью серию rerun.sh сценарий, я бы получил падение - даже в условиях низкого использования ресурсов ОС!

Наконец, обратите внимание, что источник ниже должен иметь проблему, замеченную @CL.: " Ваш модуль глючит: вы должны убедиться, что таймер не находится в ожидании до выгрузки модуля ", исправлено (в контексте hrtimer). Это, по-видимому, отвечает на мой бонусный вопрос, поскольку устраняет необходимость в любом из "MUSTHAVE" sleep в rerun.sh скрипт. Тем не менее, обратите внимание, что при 200 циклах при 4 мс требуется 0,8 с - sleep между insmod а также rmmod нужен, если мы хотим получить полный 200 тиков (иначе, на моей машине я получу только 7 тиков).

Что ж, надеюсь, я получил это прямо сейчас (по крайней мере, большинство, если оно есть) - если нет, исправления приветствуются :)

testjiffy(-hr).c

#include <linux/module.h>   /* Needed by all modules */
#include <linux/kernel.h>   /* Needed for KERN_INFO */
#include <linux/init.h>     /* Needed for the macros */
#include <linux/jiffies.h>
#include <linux/time.h>
#define MAXRUNS 200

#include <linux/hrtimer.h>


static volatile int runcount = 0;

//~ static struct timer_list my_timer;
static unsigned long period_ms;
static unsigned long period_ns;
static ktime_t ktime_period_ns;
static struct hrtimer my_hrtimer;


//~ static void testjiffy_timer_function(unsigned long data)
static enum hrtimer_restart testjiffy_timer_function(struct hrtimer *timer)
{
  int tdelay = 100;
  unsigned long tjnow;
  ktime_t kt_now;
  int ret_overrun;

  runcount++;
  if (runcount == 5) {
    while (tdelay > 0) { tdelay--; } // small delay
  }

  printk(KERN_INFO
    " %s: runcount %d \n",
    __func__, runcount);

  if (runcount < MAXRUNS) {
    tjnow = jiffies;
    kt_now = hrtimer_cb_get_time(&my_hrtimer);
    ret_overrun = hrtimer_forward(&my_hrtimer, kt_now, ktime_period_ns);
    printk(KERN_INFO
      " testjiffy jiffies %lu ; ret: %d ; ktnsec: %lld \n",
      tjnow, ret_overrun, ktime_to_ns(kt_now));
    return HRTIMER_RESTART;
  }
  else return HRTIMER_NORESTART;
}


static int __init testjiffy_init(void)
{
  struct timespec tp_hr_res;
  period_ms = 1000/HZ;
  hrtimer_get_res(CLOCK_MONOTONIC, &tp_hr_res);
  printk(KERN_INFO
    "Init testjiffy: %d ; HZ: %d ; 1/HZ (ms): %ld ; hrres: %lld.%.9ld\n",
               runcount,      HZ,        period_ms, (long long)tp_hr_res.tv_sec, tp_hr_res.tv_nsec );

  hrtimer_init(&my_hrtimer, CLOCK_MONOTONIC, HRTIMER_MODE_REL);
  my_hrtimer.function = &testjiffy_timer_function;
  period_ns = period_ms*( (unsigned long)1E6L );
  ktime_period_ns = ktime_set(0,period_ns);
  hrtimer_start(&my_hrtimer, ktime_period_ns, HRTIMER_MODE_REL);

  return 0;
}

static void __exit testjiffy_exit(void)
{
  int ret_cancel = 0;
  while( hrtimer_callback_running(&my_hrtimer) ) {
    ret_cancel++;
  }
  if (ret_cancel != 0) {
    printk(KERN_INFO " testjiffy Waited for hrtimer callback to finish (%d)\n", ret_cancel);
  }
  if (hrtimer_active(&my_hrtimer) != 0) {
    ret_cancel = hrtimer_cancel(&my_hrtimer);
    printk(KERN_INFO " testjiffy active hrtimer cancelled: %d (%d)\n", ret_cancel, runcount);
  }
  if (hrtimer_is_queued(&my_hrtimer) != 0) {
    ret_cancel = hrtimer_cancel(&my_hrtimer);
    printk(KERN_INFO " testjiffy queued hrtimer cancelled: %d (%d)\n", ret_cancel, runcount);
  }
  printk(KERN_INFO "Exit testjiffy\n");
}

module_init(testjiffy_init);
module_exit(testjiffy_exit);

MODULE_LICENSE("GPL");
Источник

Действительно возможно, что ваша функция таймера вызывается позже, чем expires что установлено Возможные причины: задержки в планировании, другие драйверы, которые слишком долго отключают прерывания (графические драйверы и драйверы WLAN являются обычными виновниками), или какой-то дурацкий BIOS, выполняющий код SMI.

Если вы хотите избежать того, чтобы одна поздняя функция таймера сдвигала все последующие вызовы таймера, вы должны запланировать соответствующий следующий таймер, не относящийся к текущему времени (jiffies), но относительно запланированного времени последнего таймера (my_timer.expires). Кроме того, используйте десять таймеров, которые вы все запланировали в начале jiffies + 1, 2, 3…

Отметка времени в журнале - это время, когда эта строка была напечатана в журнале.

Ваш модуль глючит: вы должны убедиться, что таймер не находится в режиме ожидания, прежде чем модуль будет выгружен.

Источник
Другие вопросы по тегам