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

В приведенном ниже коде есть простой Linux-модуль (драйвер), который вызывает функцию повторно 10 раз, используя add_timer при разрешении 1 jiffy (то есть, таймер планируется запустить в jiffies + 1). Используя bash script 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

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

Это, по сути, качество времени, которое я ожидаю от кода.

Однако - время от времени я получаю захват как:

[ 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

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

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

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

Итак, мои вопросы:

Ожидается ли это ожидаемое поведение от add_timer при этом разрешении (время от времени может быть пропущено)?
Если да, существует ли способ "заставить" add_timer запускать функцию в каждом слоте 4 мс, как указано в jiffy на этой платформе?
Возможно ли, что я получаю "неправильную" временную метку - например, временная метка, отражающая, когда произошла фактическая "печать" в syslog, а не когда функция действительно срабатывает?
Обратите внимание, что я не ищу разрешение периода ниже того, что соответствует 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

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

Примечание. Я также переключился на mod_timer_pinned в модуле, и это не очень помогает (журналы журнала gist получены с помощью модуля, используя эту функцию). Это изменения в 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.: большое спасибо за ответ. Хорошо, что это подтвердило, что "возможно, что ваша функция таймера вызывается при более позднем jiffy"; запустив 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

..., который выглядит следующим образом:

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

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

EDIT: просто добавьте оставшиеся комментарии:

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

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


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

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

Ответ 1

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

LDD3: 5.3. Семафоры и мьютексы - (описывая драйвер с различными требованиями отсюда): ^{"не будут выполняться никакие обращения из обработчиков прерываний или других асинхронных контекстов. Нет особых требований к задержке (времени ответа); программисты приложений понимают, что запросы ввода-вывода обычно не выполняются немедленно"}
Documentation/timers/hrtimers.txt - ^{"Код timers.c очень" плотно закодирован" вокруг приближений jiffies и 32-bitness, и был отточен и микро-оптимизирован для относительно узкого варианта использования (jiffies в относительно узком диапазоне HZ) на протяжении многих лет - и, следовательно, даже небольшие расширения для него легко нарушают концепцию колеса}
Т. Gleixner, D. Niehaus Hrtimers and Beyond: Преобразование подсистем времени Linux (pdf) - (наиболее подробно см. Также диаграммы внутри) ^{"Каскадное колесо таймера (CTW), которое было реализовано в 1997 году, заменило исходный список с двойным соединением, упорядоченный по времени, для решения проблемы масштабируемости времени привязки связанного списка O (N)... Современный подход к управлению таймером в Linux делает хорошая работа по удовлетворению чрезвычайно широкого спектра требований, но она не может обеспечить качество обслуживания, требуемое в некоторых случаях именно потому, что оно должно удовлетворять столь широкому спектру требований... Таймеры, связанные с тайм-аутом, хранятся в существующем таймер-колесе и была реализована новая подсистема, оптимизированная для требований к таймеру (высокого разрешения). hrtimers полностью основаны на человеческом времени (единицы: наносекунды)... Они хранятся в отсортированном по времени списке процессоров, реализованном как красно-черное дерево."}
API таймера с высоким разрешением [LWN.net] - ^{"По сути, механизм hrtimer остается тем же. Вместо того, чтобы использовать структуру данных" таймер-колесо ", hrtimers живут в отсортированном по времени списке, а следующий таймер истекает во главе списка. Отдельное дерево красного/черного также используется для включения и удаления событий таймера без сканирования через список. Но пока ядро остается неизменным, почти все остальное изменилось, по крайней мере, поверхностно".}
Программные прерывания и в реальном времени [LWN.net] - ^{"Механизм softirq предназначен для обработки почти почти не совсем так же важны, как и обработка аппаратных прерываний. Softirqs работают с высоким приоритетом (хотя и с интересным исключением, описанным ниже), но с включенными аппаратными прерываниями. Таким образом, они обычно вытесняют любую работу, кроме ответа на" реальный ", аппаратное прерывание... Начиная с набора исправлений 3.0 в реальном времени, тем не менее, эта возможность исчезла... В ответ, в 3.6.1-rt1, обработка softirqs снова изменилась."}
Высокие (но не слишком высокие) таймауты разрешения [LWN.net] - ^{"_ poll() и epoll_wait ( ) принимает целое число миллисекунд; select() принимает временную шкалу struct с разрешением в микросекунду, а ppoll() и pselect() принимают структурный временной интервал с разрешением наносекунд. Они все одинаковы, хотя они преобразуют это значение таймаута до максимума, с максимальным разрешением от одного до десяти миллисекунд. Программист может запрограммировать вызов pselect() с тайм-аутом в 10 наносекунд, но вызов может не вернуться до 10 миллисекунд позже, даже в отсутствие конкуренции для CPU... Это полезная функция, но она стоит за некоторыми существенными изменениями API._"}

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

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

Наконец, обратите внимание, что источник ниже должен иметь проблему, замеченную @CL.: "Ваш модуль неисправен: вы должны убедиться, что таймер не находится в ожидании до того, как модуль будет выгружен", исправлено (в контексте hrtimer). Это, похоже, отвечает на мой вопрос о бонусе, поскольку он устраняет необходимость в любом из "MUSTHAVE" sleep в rerun.sh script. Обратите внимание, что, поскольку 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");

Ответ 2

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

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

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

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