Мое основное предположение о системе «Айоваит» не соответствует

13

Мое основное предположение состоит в том, что, когда ограничивающими факторами процесса являются только диск и процессор, тогда общее системное «iowait» + использование процессора должно составлять не менее 100% одного логического процессора. (В других случаях это не будет сохраняться. Например, при загрузке файла с использованием wgetсети, часто ограничивающим фактором).

Это предположение нарушается простым тестом. Это ожидается? Если это ожидается, есть ли ряд условий, в которых я должен ожидать, что мое предположение подтвердится?

Здесь есть некоторая предыстория о «iowait»: как процессор узнает, что ожидается IO? Ответ здесь цитирует нелогичную идею, что кумулятивный iowait «может уменьшиться в определенных условиях». Интересно, может ли мой простой тест вызвать такое недокументированное условие?

ОБНОВЛЕНИЕ : Пожалуйста, перейдите к ответу .

Ответ имеет более простой тест, чем тот, который я использовал изначально. Я сохранил оригинальный вопрос ниже. Оригинальный вопрос может показать некоторые дополнительные детали.

Оригинальный вопрос

В коротком тесте я использую ddзапрос ядра для генерации случайных байтов и записи их в файл. Я запускаю ddкоманду внутри perf stat, просто чтобы подсчитать время процессора, потраченное внутри ядра. Я также запускаю его внутри perf trace -s, чтобы сообщить о времени, проведенном внутри write(). В то же время я запускаю vmstat 5в другом терминале, чтобы увидеть систему «Айоваит».

  1. Я ожидал, что по крайней мере один цельный процессор будет рассматриваться как «неактивный», то есть 100% времени он либо работает, либо останавливается, но ожидает ввода-вывода (состояние «iowait»). Не было.
  2. (Кроме того, я ожидал, что время «iowait» будет примерно соответствовать времени, потраченному на write (). Но, похоже, это не так.)

Подробные результаты и условия тестирования приведены ниже. Также показан альтернативный тест, в котором мое предположение подтвердилось. Примечание: нужно было бегать perf statвнутрь perf trace, а не наоборот. Это подробно описано здесь: Показывает ли "perf stat" (и "time"!) Неверные результаты при запуске "perf trace - s"?

Справочная информация о "Айоваит"

Ниже приводится определение, взятое из sarсправочной страницы:

% Iowait:

Процент времени, в течение которого ЦП или ЦП находились в режиме ожидания, в течение которого система имела невыполненный запрос дискового ввода-вывода.

Следовательно,% iowait означает, что с точки зрения ЦП ни одна задача не была запущена, но выполнялся хотя бы один ввод-вывод. Айоваит - это просто форма простоя, когда ничего нельзя запланировать. Это значение может или не может быть полезным при указании проблемы с производительностью, но оно говорит пользователю, что система простаивает и может потребоваться больше работы.

https://support.hpe.com/hpsc/doc/public/display?docId=c02783994

Есть также более длинная статья: Понимание ожидания ввода / вывода (или почему 0% простоя могут быть в порядке) . Это объясняет, как вы можете ясно увидеть определение из кода ядра. Код несколько изменился, но идея все еще ясна:

/*
 * Account for idle time.
 * @cputime: the CPU time spent in idle wait
 */
void account_idle_time(u64 cputime)
{
    u64 *cpustat = kcpustat_this_cpu->cpustat;
    struct rq *rq = this_rq();

    if (atomic_read(&rq->nr_iowait) > 0)
        cpustat[CPUTIME_IOWAIT] += cputime;
    else
        cpustat[CPUTIME_IDLE] += cputime;
}

В статье также показан ряд связанных экспериментов на однопроцессорной системе. Некоторые из экспериментов даже использовать ddс if=/dev/urandom ! Однако эксперименты не включают мой тест dd if=/dev/urandom of=test.out . Это только использует dd if=/dev/urandom of=/dev/null .

«IO wait» теперь немного сложнее думать, потому что мы используем многопроцессорные системы, но, думаю, я все еще понимаю это, основываясь на цитируемом коде.

Окружающая обстановка

У меня есть четыре логических процессора.

Я использую LVM и файловую систему ext4. Я не использую шифрование на моем диске или файловой системе. У меня вообще нет смонтированной сетевой файловой системы, поэтому я не читаю и не пишу сетевую файловую систему.

Приведенные ниже результаты получены из ядра 4.20.15-200.fc29.x86_64с использованием noopпланировщика ввода-вывода. Планировщик cfqввода-вывода также дает аналогичные результаты.

(Я также видел аналогичные результаты при сборке ядра, которая основывалась на аналогичной конфигурации, но была ближе к ядру версии 5.1 и использовала его mq-deadline. Так что использовался новый blk-mqкод).

Тест и результаты

$ sudo perf trace -s \
       perf stat \
       dd if=/dev/urandom of=test.out bs=1M oflag=direct count=3000

3000+0 records in
3000+0 records out
3145728000 bytes (3.1 GB, 2.9 GiB) copied, 31.397 s, 100 MB/s

 Performance counter stats for 'dd if=/dev/urandom of=test.out bs=1M oflag=direct count=3000':

         18,014.26 msec task-clock                #    0.574 CPUs utilized          
             3,199      context-switches          #    0.178 K/sec                  
                 4      cpu-migrations            #    0.000 K/sec                  
               328      page-faults               #    0.018 K/sec                  
    45,232,163,658      cycles                    #    2.511 GHz                    
    74,538,278,379      instructions              #    1.65  insn per cycle         
     4,372,725,344      branches                  #  242.737 M/sec                  
         4,650,429      branch-misses             #    0.11% of all branches        

      31.398466725 seconds time elapsed

       0.006966000 seconds user
      17.910332000 seconds sys

 Summary of events:
...
 dd (4620), 12156 events, 12.0%

   syscall            calls    total       min       avg       max      stddev
                               (msec)    (msec)    (msec)    (msec)        (%)
   --------------- -------- --------- --------- --------- ---------     ------
   read                3007 17624.985     0.002     5.861    12.345      0.21%
   write               3003 13722.837     0.004     4.570   179.928      2.63%
   openat                12     0.371     0.002     0.031     0.267     70.36%
...

Я прочитал iowaitрисунок из waколонки vmstat. Вы можете определить время выполнения теста, посмотрев на ioстолбец ( bo= 1K выходных блоков).

$ vmstat 5
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 0  0      0 5126892 176512 1486060   0   0  1788  4072  321  414  4  4 83  9  0
 1  0      0 5126632 176520 1485988   0   0     0     7  212  405  0  1 99  0  0
 0  0      0 5126884 176520 1485988   0   0     0     0  130  283  0  0 99  0  0
 0  0      0 5126948 176520 1485908   0   0     0     1  157  325  0  0 99  0  0
 0  0      0 5126412 176520 1486412   0   0   115     0  141  284  0  0 99  0  0
 0  2      0 5115724 176548 1487056   0   0     0  6019 18737 10733  3  6 89  2  0
 1  0      0 5115708 176580 1487104   0   0     3 91840 1276  990  0 13 77  9  0
 1  0      0 5115204 176600 1487128   0   0     2 91382 1382 1014  0 14 81  4  0
 1  0      0 5115268 176636 1487084   0   0     4 88281 1257  901  0 14 83  3  0
 0  1      0 5113504 177028 1487764   0   0    77 92596 1374 1111  0 15 83  2  0
 1  0      0 5114008 177036 1487768   0   0     0 113282 1460 1060  0 16 81  2  0
 1  0      0 5113472 177044 1487792   0   0     0 110821 1489 1118  0 16 74 10  0
 0  0      0 5123852 177068 1487896   0   0     0 20537  631  714  1  3 94  2  0
 0  0      0 5123852 177076 1487856   0   0     0    10  324  529  2  1 98  0  0
 2  0      0 5123852 177084 1487872   0   0     0    70  150  299  0  0 99  0  0

Результаты теста, где он действительно (внутри виртуальной машины)

Я попробовал тот же тест внутри виртуальной машины с 1 процессором, который работал с ядром 5.0.9-301.fc30.x86_64и использовал mq-deadline(и, следовательно, blk-mq). В этом тесте все сработало так, как я ожидал.

$ sudo perf trace -s \
       perf stat \
       dd if=/dev/urandom of=test.out bs=1M oflag=direct count=3000
[sudo] password for alan-sysop:
3000+0 records in
3000+0 records out
3145728000 bytes (3.1 GB, 2.9 GiB) copied, 46.8071 s, 67.2 MB/s

 Performance counter stats for 'dd if=/dev/urandom of=test.out bs=1M oflag=direct count=3000':

         18,734.89 msec task-clock                #    0.400 CPUs utilized
            16,690      context-switches          #    0.891 K/sec
                 0      cpu-migrations            #    0.000 K/sec
               328      page-faults               #    0.018 K/sec
   <not supported>      cycles
   <not supported>      instructions
   <not supported>      branches
   <not supported>      branch-misses

      46.820355993 seconds time elapsed

       0.011840000 seconds user
      18.531449000 seconds sys


 Summary of events:
...
 dd (1492), 12156 events, 38.4%

   syscall            calls    total       min       avg       max      stddev
                               (msec)    (msec)    (msec)    (msec)        (%)
   --------------- -------- --------- --------- --------- ---------     ------
   write               3003 28269.070     0.019     9.414  5764.657     22.39%
   read                3007 18371.469     0.013     6.110    14.848      0.53%
   execve                 6    10.399     0.012     1.733    10.328     99.18%
...

Выход vmstat 5:

$ vmstat 5
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----                                                                     
 r  b  swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st                                                                     
 0  0     0 726176  52128 498508    0    0  2040   231  236  731  7  5 77 11  0                                                                     
 0  0     0 726176  52136 498508    0    0     0    10   25   46  0  0 99  1  0                                                                     
 0  0     0 726208  52136 498508    0    0     0     0   29   56  0  0 100  0  0                                                                    
 0  1     0 702280  55944 511780    0    0  2260 13109 4399 9049  3 17 55 25  0                                                                     
 0  1     0 701776  56040 511960    0    0    18 129582 1406 1458 0 73  0 27  0                                                                    
 0  2     0 701524  56156 512168    0    0    22 87060  960  991  0 50  0 50  0                                                                     
 3  1     0 701524  56228 512328    0    0    14 118170 1301 1322 0 68  0 32  0                                                                    
 1  1     0 701272  56260 512392    0    0     6 86426  994  982  0 53  0 46  0                                                                     
 0  2     0 701020  56292 512456    0    0     6 56115  683  660  0 37  0 63  0                                                                     
 3  2     0 700540  56316 512504    0    0     5 33450  446  457  0 26  0 74  0                                                                     
 0  2     0 700860  56332 512536    0    0     3 16998  311  240  0 19  0 81  0                                                                     
 1  2     0 700668  56368 512616    0    0     7 32563  443  428  0 24  0 76  0                                                                     
 1  0     0 700668  56392 512648    0    0     3 20338  245  272  0 12  0 88  0                                                                   
 0  1     0 707096  56408 512920    0    0    54 20913  312  530  0 12 79  8  0                                                                     
 0  0     0 707064  56432 512920    0    0     0    49   39   64  0  0 45 55  0                                                                     
 0  0     0 707064  56432 512920    0    0     0     0   24   46  0  0 100  0  0                                                                    
 0  0     0 707064  56432 512920    0    0     0    80   28   47  0  0 100  0  0

Я попытался добавить процессор к виртуальной машине и снова протестировать. Результаты были переменными: иногда он показывал около 0% в столбце ожидания, а иногда он показывал около 50% простоя (то есть один из двух процессоров). В случае 0% «простоя» «iowait» был очень высоким, то есть более чем на один процессор. Т.е. точка ожидания 2 была неверной. Я могу с неохотой принять это очевидное ограничение «iowait» в многопроцессорных системах. (Хотя я не совсем понимаю. Если кто-то хочет объяснить это точно, это было бы здорово). Однако «холостой ход» не превышал 50% в любом случае, поэтому эти тесты все еще соответствовали моему первому предположению о «iowait».

Я попытался выключить виртуальную машину и запустить ее с 4 процессорами. Точно так же часто у меня было ровно 75% бездействия, а иногда у меня было всего лишь 50% бездействия, но я не видел более 75% бездействия (то есть более трех из четырех процессоров).

В то время как в физической системе с 4 процессорами, я все еще могу воспроизвести результат простоя более чем на 80%, как показано выше.

sourcejedi
источник
Не могли бы вы немного прокомментировать ваши ожидания? Не могли бы вы добавить, была ли реальная стоимость больше или меньше, чем вы ожидали? Я понимаю, что это в необработанных данных, это было бы немного более читабельным. Мне немного непонятно, почему вы ожидаете 1 процессор (100%). На основе одной из ваших ссылок и кода ядра, который вы цитируете, одна операция ввода-вывода переключит все время IDLE на время IOWAIT (все 4 ядра - 400%).
Филипп Коулинг
@PhilipCouling «Я ожидал, что по крайней мере один целый процессор будет« не простаивать »... Это не так». Время простоя оказалось выше, чем ожидалось, и я обвиняю, что время ожидания было ниже, чем я ожидал. В коде ядра, я думаю, this_rq()->nr_iowaitэто количество задач, которые ожидают использования только io_schedule() на текущем процессоре . Я ошибаюсь?
sourcejedi
1
Я совсем не уверен, но мне кажется удивительным, если это так. Похоже, этот сюрприз согласуется с ответом Стивена Китта, в котором он говорит, что « iowaitпытается измерить время, потраченное на ожидание ввода-вывода, в целом. Он не отслеживается конкретным процессором и не может быть» . Позвольте мне подчеркнуть, что я не уверен в этом, просто выражаю удивление.
Филипп Коулинг
@PhilipCouling, если вы запустите atop, или atopsar -c 5вы увидите цифры использования для каждого процессора. Они включают iowait, и значения iowait для каждого процессора могут показывать разные ненулевые значения :-). Или sar -P ALL 1, если вы не используете atop. Таким образом iowaitмодель была расширена для многопроцессорных систем ... Что мне неясно, так это то, что эта модель действительно применима, или это способ, который позволяет коду iowait продолжать работать, когда есть только один процессор онлайн, но это просто не заслуживает доверия в противном случае.
sourcejedi

Ответы:

7

Уведомление о содержании : этот пост содержит ссылки на различные обсуждения Linux и код. Некоторый связанный контент не соответствует действующему Кодексу поведения для StackExchange или для Linux . В основном они «оскорбляют код [но не человека]». Однако используется некоторый язык, который просто не должен повторяться. Я прошу вас избегать подражания, попугая или обсуждения такого языка.


Re: Iowait против простоя учета "противоречивы" - Iowait слишком низок

5/07/2019 12:38 Питер Зийльстра написал:

В пятницу, 5 июля 2019 года в 12:25:46 +0100 Алан Дженкинс написал:

Мое время процессора "iowait", кажется, сообщается неправильно. Вы знаете, почему это могло произойти?

Потому что iowait - это волшебное случайное число, которое не имеет смысла. Лично я предпочел бы просто удалить все это, кроме ABI : /

Также смотрите комментарий рядом с nr_iowait ()

Благодарю. Я воспринимаю [проблемы, упомянутые в текущей документации], как разные проблемы, но вы имеете в виду, что не существует особого требования (или точки), чтобы «исправить» мою проблему.

Я нашел свою проблему. Это было замечено уже пять лет назад, и исправить это было бы несложно.

Время «iowait» обновляется функцией account_idle_time():

/*
 * Account for idle time.
 * @cputime: the CPU time spent in idle wait
 */
void account_idle_time(u64 cputime)
{
    u64 *cpustat = kcpustat_this_cpu->cpustat;
    struct rq *rq = this_rq();

    if (atomic_read(&rq->nr_iowait) > 0)
        cpustat[CPUTIME_IOWAIT] += cputime;
    else
        cpustat[CPUTIME_IDLE] += cputime;
}

Это работает, как я и ожидал, если вы аппроксимируете процессорное время путем «выборки» с традиционным прерыванием по таймеру («тик»). Тем не менее, это может не сработать, если галочка отключена во время простоя для экономии энергии - NO_HZ_IDLE. Также может произойти сбой, если вы позволите отключить тик по соображениям производительности NO_HZ_FULL- потому что это требует запуска VIRT_CPU_ACCOUNTING. Большинство ядер Linux используют функцию энергосбережения. Некоторые встроенные системы не используют ни одну из функций. Вот мое объяснение:

Когда ввод-вывод завершен, устройство отправляет прерывание . Обработчик прерываний ядра активирует процесс try_to_wake_up(). Вычитает один из nr_iowaitсчетчиков:

if (p->in_iowait) {
    delayacct_blkio_end(p);
    atomic_dec(&task_rq(p)->nr_iowait);
}

Если процесс проснулся на свободном процессоре, этот процессор вызывает account_idle_time(). В зависимости от того, какая конфигурация применяется, она вызывается либо tick_nohz_account_idle_ticks()из __tick_nohz_idle_restart_tick(), либо vtime_task_switch()из finish_task_switch().

К этому времени ->nr_iowaitуже был снижен. Если оно уменьшено до нуля, то время iowait записываться не будет.

Этот эффект может варьироваться: это зависит от того, на каком процессоре происходит процесс. Если процесс активируется на том же процессоре, который получил прерывание завершения ввода-вывода, время простоя может быть учтено раньше, до ->nr_iowaitуменьшения. В моем случае я обнаружил, что CPU 0 обрабатывает прерывание ahci , посмотрев на watch cat /proc/interrupts.

Я проверил это с простым последовательным чтением:

dd if=largefile iflag=direct bs=1M of=/dev/null

Если я прикрепляю команду к CPU 0 с помощью taskset -c 0 ..., я вижу «правильные» значения для iowait. Если я прикрепляю его к другому процессору, я вижу гораздо более низкие значения. Если я запускаю команду нормально, она меняется в зависимости от поведения планировщика, которое меняется между версиями ядра. В последних ядрах (4.17, 5.1, 5.2-rc5-ish) команда, кажется, тратит около 1/4 времени на CPU 0, потому что время «iowait» сокращено до этой доли.

(Не объяснено: почему выполнение этого теста на моей виртуальной машине теперь, похоже, воспроизводит «правильный» iowait для каждого (или любого) ЦП. Я подозреваю, что это может быть связано IRQ_TIME_ACCOUNTING, хотя эта функция также используется в моих тестах вне ВМ.

Я также не подтвердил, почему подавление NO_HZ_IDLEдает «правильный» iowait для каждого процессора на 4.17+, а не на 4.16 или 4.15.

Запуск этого теста на моей виртуальной машине, похоже, воспроизводит «правильный» iowait для каждого (или любого) процессора. Это связано IRQ_TIME_ACCOUNTING. Он также используется в тестах вне ВМ, но я получаю больше прерываний при тестировании внутри ВМ. В частности, существует более 1000 «прерываний вызова функции» в секунду на виртуальном ЦП, на котором работает «dd».

Так что не стоит слишком полагаться на детали моего объяснения :-)

Здесь есть некоторая предыстория о «iowait»: как процессор узнает, что ожидается IO? Ответ здесь цитирует нелогичную идею, что кумулятивный iowait «может уменьшиться в определенных условиях». Интересно, может ли мой простой тест вызвать такое недокументированное условие?

Да.

Когда я впервые посмотрел это, я нашел разговоры о "икоте". Кроме того, проблема была проиллюстрирована тем, что кумулятивное время "Айоваит" было немонотонным. То есть он иногда прыгнул назад (уменьшился). Это было не так просто, как тест выше.

Однако, когда они исследовали, они обнаружили ту же фундаментальную проблему. Решение было предложено и прототипировано Питером Зийльстрой и Хидетоши Сето соответственно. Проблема объясняется в сопроводительном сообщении:

[RFC PATCH 0/8] переработать бухгалтерский учет в Айовите (2014-07-07)

Я не нашел никаких доказательств прогресса за пределами этого. Был открытый вопрос по одной из деталей. Кроме того, полная серия коснулась специального кода для архитектур процессоров PowerPC, S390 и IA64. Поэтому я говорю, что это не тривиально исправить.

sourcejedi
источник
2
Не могли бы вы подтвердить или опровергнуть (используя vmstat): Kernel 4.15 делает то, что вы ожидаете, независимо от включенных или отключенных состояний простоя; Ядро 4.16 не делает то, что вы ожидаете независимо. vmstat, кажется, использует /proc/stat, но я использую /sys/devices/system/cpu/cpu*/cpuidle/state*/usage, и, насколько мне известно, всегда был точным (+ - пару%). Я не могу использовать свои инструменты на старых ядрах, потому что новой информации там нет. Обратите внимание, что я ожидаю, что test1 и test3 дадут одинаковые результаты, потому что тик никогда не останавливается в состоянии ожидания 0.
Doug Smythies
1
Я хотел написать /sys/devices/system/cpu/cpu*/cpuidle/state*/timeвыше. Я могу думать только о том, чтобы разделить ядро, один раз между ядром 4.15 и 4.16, затем снова между 4.16 и 4.17. Второе разделение может пройти быстрее с помощью знаний, полученных из первого. У меня нет времени, чтобы сделать это только сейчас, может быть, через несколько дней.
Даг Смитис
1
@DougSmythies спасибо! Ваши тесты работают так же хорошо, как мои оригинальные. Мои результаты 4.15.0-1.fc28и 4.16.0-300.fc28согласны с вашими.
Sourcejedi
Хорошо, я думаю, что готов к ответу на список linux-pm. Надеюсь, у кого-то будет понимание, и мы сможем избежать деления ядра на части.
Дуг Смитис
1
@DougSmythies wtf. Первый раздел (4.15-4.16) дает github.com/torvalds/linux/commit/806486c377e3 "sched / fair: не мигрировать, если prev_cpu простаивает". Итак, я проверил с taskset -c 0v4.15 ... Выполнение ddкоманды taskset -c 2дает "правильный" iowait. Прикрепление к любому другому процессору дает «неправильный» iowait. И CPU2, где ddзаканчивается, если я не использую taskset. (Раньше я atopвидел время, затрачиваемое на процессор). Я смотрю на второй пополам, чтобы объяснить текущее поведение. На случай, возможно, был некоторый комментарий об этом во втором изменении.
sourcejedi