Ищете причину неожиданного исключения в модуле ядра Linux

У меня есть небольшой модуль ядра Linux, который является прототипом для драйвера устройства для аппаратного обеспечения, которого еще нет. Коду нужно как можно быстрее выполнить короткий бит вычисления с начала до конца с длительностью в несколько микросекунд. Я пытаюсь измерить, возможно ли это с помощью команды intel rdtscp с помощью вызова ndelay() для имитации вычисления. Я нахожу, что в 99,9% случаев он работает, как ожидалось, но в 0,1% случаев он имеет очень большую задержку, которая появляется, как будто что-то еще вытесняет код, несмотря на то, что работает внутри спин-блокировки, что должно прерывать прерывания. Это выполняется с использованием 64-битного ядра Ubuntu (4.4.0-112) без дополнительных исправлений в режиме реального времени или с низкой задержкой.

Вот пример кода, который реплицирует это поведение. Это написано как обработчик для записи файловой системы /proc для простого тестирования, но я только показал функцию, которая фактически вычисляет задержки:

#define ITERATIONS 50000
#define SKIPITER 10
DEFINE_SPINLOCK(timer_lock);
static int timing_test_show(struct seq_file *m, void *v) 
{
  uint64_t i;
  uint64_t first, start, stop, delta, max=0, min=1000000;
  uint64_t avg_ticks;
  uint32_t a, d, c;
  unsigned long flags;
  int above30k=0;

  __asm__ volatile ("rdtscp" : "=a" (a), "=d" (d) : : "rcx");
  first = a | (((uint64_t)d)<<32);
  for (i=0; i<ITERATIONS; i++) {
    spin_lock_irqsave(&timer_lock, flags);
    __asm__ volatile ("rdtscp" : "=a" (a), "=d" (d) : : "rcx");
    start = a | (((uint64_t)d)<<32);
    ndelay(1000);
    __asm__ volatile ("rdtscp" : "=a" (a), "=d" (d) : : "rcx");
    stop = a | (((uint64_t)d)<<32);
    spin_unlock_irqrestore(&timer_lock, flags);
    if (i < SKIPITER) continue;
    delta = stop-start;
    if (delta < min) min = delta;
    if (delta > max) max = delta;
    if (delta > 30000) above30k++;
  }
  seq_printf(m, "min: %llu max: %llu above30k: %d\n", min, max, above30k);
  avg_ticks = (stop - first) / ITERATIONS;
  seq_printf(m, "Average total ticks/iteration: %llu\n", avg_ticks);
  return 0;
}

Тогда, если я запустил:

# cat /proc/timing_test
min: 4176 max: 58248 above30k: 56
Average total ticks/iteration: 4365

Это на процессоре Core i7 с песочным мостом 3.4 ГГц. ~ 4200 тиков TSC примерно соответствует минимальной задержке в 1 микросекунду. Примерно в 0,1% случаев я вижу задержки в 10 раз дольше, чем ожидалось, и в некоторых случаях я видел столько раз, сколько 120 000 клещей.

Эти задержки слишком велики, чтобы быть пропуском кеша даже в DRAM. Поэтому я думаю, что это либо должно быть несколько промахов в кеше, либо другая задача, вытесняющая процессор в середине моего критического раздела. Я хотел бы понять возможные причины этого, чтобы увидеть, есть ли они что-то, что мы можем устранить, или если нам нужно перейти к настраиваемому процессору/FPGA-решению.

Вещи, которые я пробовал:

• Я подумал, может ли это быть вызвано промахами кеша. Я не думаю, что это может быть так, поскольку я игнорирую первые несколько итераций, которые должны загружать кеш. Я проверил, исследуя разборку, что между двумя вызовами rdtscp нет операций с памятью, поэтому я думаю, что единственные возможные промахи в кэше - для кэша команд.
• На всякий случай, я переместил вызовы spin_lock вокруг внешнего цикла. Тогда после первой итерации не должно быть никаких промахов в кеше. Однако это еще больше усугубило проблему.
• Я слышал, что прерывание SMM является неприемлемым и в основном прозрачным и может вызвать нежелательное преодоление. Тем не менее, вы можете прочитать счет прерывания SMI с помощью rdmsr на MSR_SMI_COUNT. Я попытался добавить, что до и после, и нет прерываний SMM, происходящих во время моего кода.
• Я понимаю, что есть также межпроцессорные прерывания в SMP-системах, которые могут прерывать, но я смотрел на /proc/interrupts до и после и не видел достаточно их, чтобы объяснить это поведение.
• Я не знаю, учитывает ли ndelay() переменную тактовую частоту, но я думаю, что тактовая частота процессора изменяется только в 2 раза, поэтому это не должно приводить к изменению> 10x.
• Я загрузился с nopti, чтобы отключить изоляцию таблицы страниц в случае возникновения проблем.

Ответы

timingtest % uname -a
Linux xxxxxx 4.15.0-42-generic #45-Ubuntu SMP Thu Nov 15 19:32:57 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

timingtest % sudo cat /proc/timing_test
min: 3783 max: 66883 above30k: 20
Average total ticks/iteration: 4005

timingtest % sudo cat /proc/timing_test
min: 3783 max: 64282 above30k: 19
Average total ticks/iteration: 4010

timingtest % sudo cat /proc/timing_test
min: 3308 max: 43301 above30k: 2
Average total ticks/iteration: 3611

timingtest % sudo cat /proc/timing_test
min: 3303 max: 44244 above30k: 2
Average total ticks/iteration: 3600

for (delta=0,c=0; delta<500; delta++) {c++; c|=(c<<24); c&=~(c<<16);}

__asm__ volatile ("rdmsr" : "=a" (a), "=d" (d) : "c"(0x34) : );
smi_after = (a | (((uint64_t)d)<<32));

timingtest % sudo trace-cmd record -o trace.dat -p function_graph cat /proc/timing_test 
  plugin 'function_graph'
min: 3559 max: 4161 above30k: 0
Average total ticks/iteration: 5863
...