Mi suposición básica es que cuando los únicos factores limitantes de un proceso son el disco y la CPU, entonces el "iowait" total del sistema + el uso de la CPU debería ser igual al menos al 100% de una CPU lógica. (En otros casos, esto no se mantendrá. Por ejemplo, al descargar un archivo usando wget, la red suele ser el factor limitante).

Esta suposición es violada por una simple prueba. ¿Se espera esto? Si se espera, ¿hay un conjunto de condiciones en las que debería esperar que mi suposición sea cierta?

Aquí hay algunos antecedentes sobre "iowait": ¿Cómo sabe una CPU que hay IO pendiente? La respuesta aquí cita la idea contraintuitiva, que el iowait acumulativo "puede disminuir en ciertas condiciones". ¿Me pregunto si mi simple prueba puede desencadenar una condición tan indocumentada?

ACTUALIZACIÓN : salte a la respuesta .

La respuesta tiene una prueba más simple que la que usé originalmente. Preservé la pregunta original a continuación. La pregunta original podría mostrar algunos detalles adicionales.

Pregunta original

En una prueba corta, uso ddpara solicitar que el núcleo genere bytes aleatorios y los escriba en un archivo. Ejecuto el ddcomando dentro perf stat, solo para obtener un recuento del tiempo de CPU pasado dentro del núcleo. También lo ejecuto adentro perf trace -s, para informar el tiempo que pasé adentro write(). Al mismo tiempo, corro vmstat 5en otra terminal, para ver el sistema "iowait".

1. Esperaba ver al menos una CPU completa como "no inactiva", es decir, el 100% del tiempo está en ejecución o detenida pero esperando IO (estado "iowait"). No era.
2. (Además, esperaba ver que el tiempo de "iowait" coincidiera aproximadamente con el tiempo empleado en write (). Pero no parecía ser así).

Los resultados detallados y el entorno de prueba se muestran a continuación. También se muestra una prueba alternativa, donde mi suposición se mantuvo. Nota: era necesario correr perf statdentro perf trace, no al revés. Aquí se detalla: ¿Muestra "perf stat" (y "time") resultados incorrectos al ejecutar "perf trace - s"?

Información básica sobre "iowait"

La siguiente es la definición tomada de la página de sarmanual:

% iowait:

Porcentaje de tiempo que la CPU o las CPU estuvieron inactivas durante las cuales el sistema tuvo una solicitud de E / S de disco pendiente.

Por lo tanto,% iowait significa que desde el punto de vista de la CPU, no se podían ejecutar tareas, pero al menos una E / S estaba en progreso. iowait es simplemente una forma de tiempo inactivo cuando no se puede programar nada. El valor puede o no ser útil para indicar un problema de rendimiento, pero le dice al usuario que el sistema está inactivo y podría haber tomado más trabajo.

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

También hay un artículo más extenso: Comprender la espera de E / S (o por qué 0% de inactividad puede estar bien) . Esto explica cómo puede ver la definición claramente desde el código del núcleo. El código ha cambiado un poco, pero la idea aún está clara:

/*
 * 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;
}

El artículo también muestra una serie de experimentos relacionados en un sistema de CPU única. ¡Algunos de los experimentos incluso se usan ddcon if=/dev/urandom ! Sin embargo, los experimentos no incluyen mi prueba dd if=/dev/urandom of=test.out . Solo usa dd if=/dev/urandom of=/dev/null .

"IO wait" es un poco más difícil de pensar ahora porque usamos sistemas multi-CPU, pero creo que todavía lo entiendo, según el código citado.

Ambiente

Tengo cuatro CPU lógicas.

Yo uso LVM, y el sistema de archivos ext4. No estoy usando ningún cifrado en mi disco o sistema de archivos. No tengo ningún sistema de archivos de red montado, por lo que no estoy leyendo ni escribiendo un sistema de archivos de red.

Los resultados a continuación son del kernel 4.20.15-200.fc29.x86_64, usando el noopplanificador IO. El cfqplanificador de IO también da resultados similares.

(También he visto resultados similares en una compilación del kernel que se basó en una configuración similar, pero estaba más cerca de la versión 5.1 del kernel y la que usaba mq-deadline. Así que estaba usando el nuevo blk-mqcódigo).

Prueba y resultados

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

Leí la iowaitfigura de la wacolumna de vmstat. Puede saber cuándo se está ejecutando la prueba mirando la iocolumna ( bo= salida de 1K bloques).

$ 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

Resultados de la prueba donde se mantiene (dentro de una VM)

Intenté la misma prueba dentro de una VM con 1 CPU, que estaba ejecutando el kernel 5.0.9-301.fc30.x86_64y usando mq-deadline(y por lo tanto blk-mq). En esta prueba, funcionó como esperaba.

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

Salida de 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

Intenté agregar una CPU en caliente a la VM y volver a probar. Los resultados fueron variables: a veces mostraba aproximadamente el 0% en la columna inactiva, y a veces mostraba aproximadamente el 50% inactivo (es decir, una de cada dos CPU). En el caso del 0% de "inactivo", "iowait" era muy alto, es decir, valía más de una CPU. Es decir, mi punto de expectativa 2 no era correcto. Puedo aceptar a regañadientes esta aparente limitación de "iowait" en sistemas con múltiples CPU. (Aunque no lo entiendo del todo. Si alguien quiere explicarlo exactamente, sería genial). Sin embargo, "inactivo" no estaba por encima del 50% en ninguno de los casos, por lo que estas pruebas aún eran consistentes con mi primera suposición sobre "iowait".

Intenté apagar la VM y comenzarla con 4 CPU. Del mismo modo, a menudo tenía exactamente un 75% de inactividad, y a veces tenía tan solo un 50% de inactividad, pero no veía más del 75% de inactividad (es decir, más de tres de cada cuatro CPU).

Mientras que en el sistema físico con 4 CPU, todavía puedo reproducir el resultado de más del 80% de inactividad como se muestra arriba.

Aviso de contenido : esta publicación incluye enlaces a varios debates y códigos de Linux. Algunos contenidos vinculados no cumplen con el Código de conducta actual para StackExchange o Linux . Principalmente "insultan el código [pero no a la persona]". Sin embargo, se utiliza algún lenguaje, que simplemente no debe repetirse. Le pido que evite imitar, repetir o debatir dicho lenguaje.

Re: iowait vs contabilidad inactiva es "inconsistente" - iowait es demasiado bajo

El 07/05/2019 12:38, Peter Zijlstra escribió:

El viernes, 05 de julio de 2019 a las 12:25:46 PM +0100, Alan Jenkins escribió:

Parece que se informó incorrectamente el tiempo de mi CPU "iowait". ¿Sabes por qué esto podría pasar?

Porque iowait es un número aleatorio mágico que no tiene sentido sensato. Personalmente, preferiría eliminar todo, excepto ABI : /

Ver también el comentario cerca de nr_iowait ()

Gracias. Considero [los problemas mencionados en la documentación actual] como problemas diferentes, pero quiere decir que no hay mucha demanda (o punto) para "solucionar" mi problema.

Encontré mi problema. Ya se notó hace cinco años, y no sería trivial arreglarlo.

La función actualiza el tiempo "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;
}

Esto funciona como esperaba, si está aproximando el tiempo de la CPU "muestreando" con la interrupción tradicional del temporizador ("tick"). Sin embargo, puede que no funcione si la marca está desactivada durante el tiempo de inactividad para ahorrar energía NO_HZ_IDLE. También puede fallar si permite que la marca se desactive por razones de rendimiento NO_HZ_FULL, porque eso requiere comenzar VIRT_CPU_ACCOUNTING. La mayoría de los núcleos de Linux utilizan la función de ahorro de energía. Algunos sistemas integrados no utilizan ninguna de las características. Aquí está mi explicación:

Cuando se completa el IO, el dispositivo envía una interrupción . El controlador de interrupción del núcleo activa el proceso usando try_to_wake_up(). Resta uno del nr_iowaitcontador:

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

Si el proceso se despierta en una CPU inactiva, esa CPU llama account_idle_time(). Dependiendo de qué configuración se aplique, esto se llama desde tick_nohz_account_idle_ticks()from __tick_nohz_idle_restart_tick()o from vtime_task_switch()from finish_task_switch().

Para este momento, ->nr_iowaitya ha sido decrementado. Si se reduce a cero, no se registrará el tiempo de espera.

Este efecto puede variar: depende de la CPU en la que se active el proceso. Si el proceso se despierta en la misma CPU que recibió la interrupción de finalización de E / S, el tiempo de inactividad podría contabilizarse antes, antes de ->nr_iowaitdisminuir. En mi caso, encontré que la CPU 0 maneja la interrupción ahci , al mirar watch cat /proc/interrupts.

Probé esto con una simple lectura secuencial:

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

Si fijo el comando a la CPU 0 usando taskset -c 0 ..., veo valores "correctos" para iowait. Si lo conecto a una CPU diferente, veo valores mucho más bajos. Si ejecuto el comando normalmente, varía según el comportamiento del planificador, que ha cambiado entre las versiones del kernel. En núcleos recientes (4.17, 5.1, 5.2-rc5-ish), el comando parece gastar aproximadamente 1/4 del tiempo en la CPU 0, porque el tiempo "iowait" se reduce a esa fracción.

(No se explica: por qué ejecutar esta prueba en mi máquina virtual ahora parece reproducir iowait "correcto", para cada (o cualquier) CPU. Sospecho que esto podría implicar IRQ_TIME_ACCOUNTING, aunque esta característica también se está utilizando en mis pruebas fuera de la VM.

Tampoco he confirmado exactamente por qué la supresión NO_HZ_IDLEda iowait "correcto" para cada CPU en 4.17+, pero no en 4.16 o 4.15.

Ejecutar esta prueba en mi máquina virtual parece reproducir iowait "correcto", para cada (o cualquier) CPU. Esto se debe a IRQ_TIME_ACCOUNTING. También se usa en las pruebas fuera de la VM, pero recibo más interrupciones cuando pruebo dentro de la VM. Específicamente, hay más de 1000 "interrupciones de llamadas de función" por segundo en la CPU virtual en la que se ejecuta "dd".

Por lo tanto, no debe confiar demasiado en los detalles de mi explicación :-)

Aquí hay algunos antecedentes sobre "iowait": ¿Cómo sabe una CPU que hay IO pendiente? La respuesta aquí cita la idea contraintuitiva, que el iowait acumulativo "puede disminuir en ciertas condiciones". ¿Me pregunto si mi simple prueba puede desencadenar una condición tan indocumentada?

Si.

Cuando busqué esto por primera vez, encontré hablar de "hipo". Además, el problema fue ilustrado al mostrar que el tiempo acumulativo "iowait" no era monótono. Es decir, a veces saltó hacia atrás (disminuyó). No fue tan sencillo como la prueba anterior.

Sin embargo, cuando investigaron encontraron el mismo problema fundamental. Peter Zijlstra y Hidetoshi Seto propusieron y crearon una solución, respectivamente. El problema se explica en el mensaje de portada:

[RFC PATCH 0/8] retrabaja la contabilidad de iowait (2014-07-07)

No encontré evidencia de progreso más allá de esto. Hubo una pregunta abierta sobre uno de los detalles. Además, la serie completa tocó código específico para las arquitecturas de CPU PowerPC, S390 e IA64. Entonces digo que esto no es trivial de arreglar.