Mon hypothèse de base est que lorsque les seuls facteurs limitants d'un processus sont le disque et le processeur, alors le total du système "iowait" + l'utilisation du processeur doit être égal à au moins 100% d'un processeur logique. (Dans d'autres cas, cela ne tiendra pas. Par exemple, lors du téléchargement d'un fichier à l'aide wget, le réseau est souvent le facteur limitant).

Cette hypothèse est violée par un simple test. Est-ce attendu? Si cela est prévu, y a-t-il un ensemble de conditions dans lesquelles je dois m'attendre à ce que mon hypothèse se vérifie?

Il y a quelques informations sur "iowait" ici: Comment un processeur sait-il qu'il y a des E / S en attente? La réponse cite ici l'idée contre-intuitive, que les iowait cumulatifs "peuvent diminuer dans certaines conditions". Je me demande si mon simple test peut déclencher une telle condition non documentée?

MISE À JOUR : Veuillez passer à la réponse .

La réponse a un test plus simple que celui que j'ai utilisé à l'origine. J'ai conservé la question d'origine ci-dessous. La question d'origine peut montrer des détails supplémentaires.

Question d'origine

Dans un court test, j'utilise ddpour demander au noyau de générer des octets aléatoires et de les écrire dans un fichier. J'exécute la ddcommande à l'intérieur perf stat, juste pour obtenir un compte du temps CPU passé à l'intérieur du noyau. Je l'ai également exécuté à l'intérieur perf trace -s, pour signaler le temps passé à l'intérieur write(). En même temps, je cours vmstat 5dans un autre terminal, pour voir le système "iowait".

1. Je m'attendais à voir au moins un processeur entier comme "non inactif", c'est-à-dire 100% du temps, qu'il soit en cours d'exécution, ou arrêté mais en attente d'E / S (état "iowait"). Ce n'était pas.
2. (De plus, je m'attendais à voir le temps "iowait" correspondre à peu près au temps passé en écriture (). Mais il ne semblait pas le faire.)

Les résultats détaillés et l'environnement de test sont présentés ci-dessous. Un autre test est également présenté, où mon hypothèse était vraie. Remarque: il fallait courir à l' perf statintérieur perf trace, pas l'inverse. Ceci est détaillé ici: Est - ce que "perf stat" (et "time"!) Affiche des résultats incorrects lors de l'exécution de "perf trace-s"?

Informations générales sur "iowait"

Voici la définition tirée de la sarpage de manuel:

% iowait:

Pourcentage de temps pendant lequel le ou les CPU étaient inactifs pendant lesquels le système avait une demande d'E / S disque en attente.

Par conséquent,% iowait signifie que du point de vue CPU, aucune tâche n'était exécutable, mais au moins une E / S était en cours. iowait est simplement une forme de temps d'inactivité où rien ne peut être programmé. La valeur peut être utile ou non pour indiquer un problème de performances, mais elle indique à l'utilisateur que le système est inactif et aurait pu prendre plus de travail.

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

Il y a aussi un article plus long: Comprendre l'attente des E / S (ou pourquoi 0% d'inactivité peut être OK) . Cela explique comment vous pouvez voir clairement la définition à partir du code du noyau. Le code a quelque peu changé, mais l'idée est toujours claire:

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

L'article montre également un certain nombre d'expériences connexes sur un système à processeur unique. Certaines des expériences utilisent même ddavec if=/dev/urandom ! Cependant, les expériences n'incluent pas mon test dd if=/dev/urandom of=test.out . Il utilise seulement dd if=/dev/urandom of=/dev/null .

"IO wait" est un peu plus délicat à penser maintenant parce que nous utilisons des systèmes multi-CPU, mais je pense que je le comprends toujours, basé sur le code cité.

Environnement

J'ai quatre processeurs logiques.

J'utilise LVM et le système de fichiers ext4. Je n'utilise aucun chiffrement sur mon disque ou système de fichiers. Je n'ai aucun système de fichiers réseau monté, donc je ne lis ni n'écris aucun système de fichiers réseau.

Les résultats ci-dessous proviennent du noyau 4.20.15-200.fc29.x86_64, utilisant le noopplanificateur d'E / S. Le cfqplanificateur d'E / S donne également des résultats similaires.

(J'ai également vu des résultats similaires sur une construction de noyau qui était basée sur une configuration similaire, mais était plus proche de la version 5.1 du noyau et de son utilisation mq-deadline. Cela utilisait donc le nouveau blk-mqcode).

Test et résultats

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

J'ai lu la iowaitfigure de la wacolonne de vmstat. Vous pouvez savoir quand le test est en cours d'exécution en regardant la iocolonne ( bo= 1K blocs de sortie).

$ 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

Résultats des tests là où ils se trouvent (à l'intérieur d'une machine virtuelle)

J'ai essayé le même test à l'intérieur d'une machine virtuelle avec 1 CPU, qui exécutait le noyau 5.0.9-301.fc30.x86_64et utilisait mq-deadline(et donc blk-mq). Dans ce test, cela a fonctionné comme je m'y attendais.

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

Sortie 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

J'ai essayé d'ajouter à chaud un processeur à la machine virtuelle et de tester à nouveau. Les résultats étaient variables: parfois, ils montraient environ 0% dans la colonne inactive, et parfois ils montraient environ 50% inactifs (c'est-à-dire un processeur sur deux). Dans le cas de 0% "inactif", "iowait" était très élevé, c'est-à-dire la valeur de plus d'un CPU. C'est-à-dire que mon point d'attente 2 n'était pas correct. Je peux accepter à contrecœur cette apparente limitation de "iowait" sur les systèmes multi-CPU. (Bien que je ne le comprenne pas très bien. Si quelqu'un veut l'expliquer exactement, ce serait bien). Cependant, "ralenti" n'était pas supérieur à 50% dans les deux cas, donc ces tests étaient toujours cohérents avec ma première hypothèse sur "iowait".

J'ai essayé d'arrêter la machine virtuelle et de la démarrer avec 4 processeurs. De même, souvent j'avais exactement 75% d'inactivité, et parfois j'avais aussi peu que 50% d'inactivité, mais je ne voyais pas plus de 75% d'inactivité (c'est-à-dire plus de trois CPU sur quatre).

Alors que sur le système physique avec 4 CPU, je peux toujours reproduire le résultat de plus de 80% d'inactivité comme indiqué ci-dessus.

Avis de contenu : cet article contient des liens vers diverses discussions et codes Linux. Certains contenus liés ne respectent pas le code de conduite actuel pour StackExchange ou pour Linux . Surtout, ils "insultent le code [mais pas la personne]". Quel que soit le langage utilisé, il ne faut tout simplement pas le répéter. Je vous demande d'éviter d'imiter, de parrotter ou de débattre un tel langage.

Re: iowait vs comptabilité inactive est "incohérent" - iowait est trop faible

Le 05/07/2019 12:38, Peter Zijlstra a écrit:

Le ven.05 juil.2019 à 12:25:46 PM +0100, Alan Jenkins a écrit:

Mon temps CPU "iowait" semble être signalé de manière incorrecte. Savez-vous pourquoi cela pourrait arriver?

Parce que iowait est un nombre aléatoire magique qui n'a aucune signification sensée. Personnellement, je préfère simplement supprimer le tout, sauf ABI : /

Voir aussi le commentaire près de nr_iowait ()

Merci. Je considère [les problèmes mentionnés dans la documentation actuelle] comme étant des problèmes différents, mais vous voulez dire qu'il n'y a pas beaucoup de demande (ou de point) pour "résoudre" mon problème.

J'ai trouvé mon problème. Il a déjà été remarqué il y a cinq ans, et il ne serait pas trivial de le réparer.

Le temps "iowait" est mis à jour par la fonction 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;
}

Cela fonctionne comme je m'y attendais, si vous approximez le temps processeur en "échantillonnant" avec l'interruption de la minuterie traditionnelle ("tick"). Cependant, cela peut ne pas fonctionner si la coche est désactivée pendant la période d'inactivité pour économiser l'énergie - NO_HZ_IDLE. Il peut également échouer si vous autorisez la désactivation du tick pour des raisons de performances - NO_HZ_FULL- car cela nécessite un démarrage VIRT_CPU_ACCOUNTING. La plupart des noyaux Linux utilisent la fonction d'économie d'énergie. Certains systèmes intégrés n'utilisent aucune de ces fonctionnalités. Voici mon explication:

Une fois l'IO terminée, l'appareil envoie une interruption . Le gestionnaire d'interruption du noyau réveille le processus à l'aide de try_to_wake_up(). Il soustrait un du nr_iowaitcompteur:

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

Si le processus est réveillé sur un processeur inactif, ce processeur appelle account_idle_time(). En fonction de la configuration qui s'applique, cela est appelé à partir tick_nohz_account_idle_ticks()de __tick_nohz_idle_restart_tick()ou à partir vtime_task_switch()de finish_task_switch().

À ce moment, ->nr_iowaita déjà été décrémenté. S'il est réduit à zéro, aucun temps d'attente ne sera enregistré.

Cet effet peut varier: cela dépend de la CPU sur laquelle le processus est réveillé. Si le processus est réveillé sur le même processeur qui a reçu l'interruption de fin d'E / S, le temps d'inactivité peut être comptabilisé plus tôt, avant d' ->nr_iowaitêtre décrémenté. Dans mon cas, j'ai trouvé que le CPU 0 gère l' interruption ahci , en regardant watch cat /proc/interrupts.

J'ai testé cela avec une simple lecture séquentielle:

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

Si j'épingle la commande à CPU 0 en utilisant taskset -c 0 ..., je vois des valeurs "correctes" pour iowait. Si je l'épingle sur un autre processeur, je vois des valeurs beaucoup plus faibles. Si j'exécute la commande normalement, elle varie en fonction du comportement du planificateur, qui a changé entre les versions du noyau. Dans les noyaux récents (4.17, 5.1, 5.2-rc5-ish), la commande semble passer environ 1/4 du temps sur le CPU 0, car le temps "iowait" est réduit à cette fraction.

(Non expliqué: pourquoi l'exécution de ce test sur ma machine virtuelle semble maintenant reproduire un iowait "correct", pour chaque (ou n'importe quel) processeur. Je soupçonne que cela pourrait impliquer IRQ_TIME_ACCOUNTING, bien que cette fonctionnalité soit également utilisée dans mes tests en dehors de la machine virtuelle.

Je n'ai pas non plus confirmé exactement pourquoi la suppression NO_HZ_IDLEdonne un iowait "correct" pour chaque CPU sur 4.17+, mais pas sur 4.16 ou 4.15.

L'exécution de ce test sur ma machine virtuelle semble reproduire un iowait "correct", pour chaque (ou n'importe quel) processeur. Cela est dû à IRQ_TIME_ACCOUNTING. Il est également utilisé dans les tests en dehors de la machine virtuelle, mais j'obtiens plus d'interruptions lors des tests à l'intérieur de la machine virtuelle. Plus précisément, il y a plus de 1 000 «interruptions d'appel de fonction» par seconde sur le processeur virtuel sur lequel «dd» s'exécute.

Il ne faut donc pas trop compter sur les détails de mon explication :-)

Il y a quelques informations sur "iowait" ici: Comment un processeur sait-il qu'il y a des E / S en attente? La réponse cite ici l'idée contre-intuitive, que les iowait cumulatifs "peuvent diminuer dans certaines conditions". Je me demande si mon simple test peut déclencher une telle condition non documentée?

Oui.

Quand j'ai recherché ceci pour la première fois, j'ai trouvé parler de "hoquet". De plus, le problème a été illustré en montrant que le temps cumulé "iowait" n'était pas monotone. C'est-à-dire qu'il a parfois sauté en arrière (diminué). Ce n'était pas aussi simple que le test ci-dessus.

Cependant, lorsqu'ils ont enquêté, ils ont découvert le même problème fondamental. Une solution a été proposée et prototypée, respectivement par Peter Zijlstra et Hidetoshi Seto. Le problème est expliqué dans le message de couverture:

[RFC PATCH 0/8] retravailler la comptabilité iowait (2014-07-07)

Je n'ai trouvé aucune preuve de progrès au-delà de cela. Il y avait une question ouverte sur l'un des détails. De plus, la série complète a touché un code spécifique pour les architectures CPU PowerPC, S390 et IA64. Je dis donc que ce n'est pas trivial à corriger.