Поиск причины неожиданного выгрузки в модуле ядра Linux

Question

У меня есть небольшой модуль ядра 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

Это на песчаном мосту поколения 3,4 ГГц Core i7. Приблизительно 4200 тиков TSC примерно одинаковы для задержки чуть более 1 микросекунды. Приблизительно в 0,1% случаев я вижу задержки примерно в 10 раз дольше, чем ожидалось, а в некоторых случаях я видел времена, которые достигли 120000 тиков.

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

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

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

Answer 1

Еще одна вещь, которую я только что заметил, это то, что неясно, что ndelay() делает. Может быть, вы должны показать это так, чтобы в нем скрывались нетривиальные проблемы.

Например, я однажды заметил, что мой фрагмент кода драйвера ядра был все еще вытеснен, когда в нем была утечка памяти, поэтому, как только он достиг некоторого предела водяного знака, он был отложен, даже если он отключил прерывания.

Answer 2

120000 тиков, которые вы наблюдали в крайних случаях, очень похоже на обработчик SMM. Меньшие значения могли быть вызваны целым рядом микроархитектурных событий (кстати, вы проверили все доступные вам счетчики производительности?), Но это должно быть вызвано подпрограммой, написанной кем-то, кто не писал его / ее код для достижения минимальной задержки.

Однако вы заявили, что проверили, что SMI не наблюдается. Это наводит меня на мысль, что либо что-то не так с возможностями ядра для их подсчета / отчета или с вашим методом для их наблюдения. Охота после SMI без аппаратного отладчика может быть неудачной попыткой.

• Разве SMI_COUNT не менялся во время курса эксперимента или все время был точно нулевым? Последнее может указывать на то, что оно ничего не учитывает, если только ваша система полностью свободна от SMI, в чем я сомневаюсь в случае обычного Sandy Bridge.
• Может случиться так, что SMI доставляются другому ядру в вашей системе, и обработчик SMM синхронизирует другие ядра с помощью какого-то механизма, который не отображается в SMI_COUNT. Вы проверяли другие ядра?
• В общем, я бы рекомендовал начать сокращение вашей тестируемой системы, чтобы исключить как можно больше вещей. Вы пытались загрузить его с одним ядром и без поддержки гиперпоточности в BIOS? Вы пытались запустить тот же код в системе, которая, как известно, не имеет SMI? То же самое касается отключения Turbo Boost и частотного масштабирования в BIOS. Как можно больше времени должно быть связано.

Answer 3

К вашему сведению, в моей системе:

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

Повторяя ваш пример (с помощью ndelay(1000);), я получаю:

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

Повторяя ваш пример (с помощью udelay (1);), я получаю:

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

ndelay (), udelay (), mdelay () предназначены для использования в атомарном контексте, как указано здесь: https://www.kernel.org/doc/Documentation/timers/timers-howto.txt они полагаются на функцию __const_udelay () это экспортированный символ vmlinux (используя: инструкции LFENCE/RDTSC).

Во всяком случае, я заменил задержку с:

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

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

Я также попытался с _cli()/_sti(), local_bh_disable()/local_bh_enable() и preempt_disable () / preempt_enable () без успеха.

Examinig SMM прерывает (до и после задержки) с:

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

Я всегда получаю один и тот же номер (нет SMI или регистр не обновляется).

Выполняя команду cat с помощью trace-cmd для изучения происходящего, я получаю результаты, которые не настолько разбросаны по времени. (!?)

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
...

В моей системе проблему можно решить с помощью функции управления качеством обслуживания, см. ( https://access.redhat.com/articles/65410). Надеюсь это поможет