FIO runtime différent de gettimeofday()

Question

J'essaie de mesurer le temps d'exécution du benchmark FIO. Je suis, actuellement, le fais envelopper l'appel FIO entre gettimeofday():

gettimeofday(&startFioFix, NULL); 
FILE* process = popen("fio --name=randwrite --ioengine=posixaio rw=randwrite --size=100M --direct=1 --thread=1 --bs=4K", "r"); 
gettimeofday(&doneFioFix, NULL); 

et calculer le temps écoulé comme:

double tstart = startFioFix.tv_sec + startFioFix.tv_usec/1000000.; 
double tend = doneFioFix.tv_sec + doneFioFix.tv_usec/1000000.; 
double telapsed = (tend - tstart); 

Maintenant, la question (s) est

1. le temps telapsed est différent ( plus grand) que le runt par la sortie FIO. Pouvez-vous s'il vous plaît m'aider à comprendre pourquoi? comme le fait peut être vu dans la sortie FIO:

   randwrite: (g=0): rw=randwrite, bs=4K-4K/4K-4K/4K-4K, ioengine=posixaio, iodepth=1 
   fio-2.2.8 
   Starting 1 thread 
   
   randwrite: (groupid=0, jobs=1): err= 0: pid=3862: Tue Nov 1 18:07:50 2016 
   write: io=102400KB, bw=91674KB/s, iops=22918, runt= 1117msec 
   ... 
   

   et telapsed est:

   telapsed: 1.76088 seconds 
   

2. ce qui est le temps réel pris par l'exécution FIO: a) avorton donnée par FIO, ou b) le temps écoulé par getttimeofday()

3. Comment mesure-t-FIO son avorton? (Probablement, cette question liée à 1.)

PS: J'ai essayé de remplacer le gettimeofday (avec std :: :: high_resolution_clock :: chrono maintenant()), mais il se comporte également les mêmes (par même , Je veux dire, il donne également plus de temps écoulé que runt)

Merci d'avance, pour votre temps et votre aide.

Answer 1

Un point rapide: gettimeofday() sur Linux utilise une horloge qui ne pas nécessairement cocher à un intervalle constant et peut même se déplacer vers l'arrière (voir http://man7.org/linux/man-pages/man2/gettimeofday.2.html et https://stackoverflow.com/a/3527632/4513656) - cela peut rendre telapsed peu fiables (voire négatif).

1. Votre gettimeofday/popen/mesure gettimeofday (telapsed) va être: le processus de fio démarrage (c.-à-fork + exec sous Linux) se sont écoulées + initialisation FIO (par exemple la création de fil parce que je vois --thread, initialisation ioengine) + fio travail écoulé (runt) + fio arrêt écoulé + arrêt du processus écoulé). Vous comparez cela à runt qui est un sous-composant de telapsed. Il est peu probable que tous les composants non-runt vont se produire instantanément (c.-à-d. Prendre 0 usecs) donc on s'attend à ce que runt soit plus petit que telapsed. Essayez d'exécuter fio avec --debug=all juste pour voir tout ce qu'il fait en plus de soumettre les E/S pour le travail.
2. Il est difficile de répondre parce que cela dépend de ce que vous voulez dire quand vous dites "exécution fio" et pourquoi (c'est-à-dire la question est difficile à interpréter de manière non ambiguë). Êtes-vous intéressé par combien de temps fio a réellement passé à essayer de soumettre des E/S pour un travail donné (runt)? Cela vous intéresse-t-il de savoir combien de temps votre système doit démarrer/arrêter un nouveau processus pour essayer de soumettre des E/S pendant une période donnée (telapsed)? Êtes-vous intéressé par combien de temps CPU a été passé à soumettre des E/S (aucune de ces réponses)?Donc, parce que je suis confus, je vais vous poser quelques questions à la place: sur quoi allez-vous utiliser le résultat et pourquoi? Pourquoi ne pas regarder le code source? https://github.com/axboe/fio/blob/7a3b2fc3434985fa519db55e8f81734c24af274d/stat.c#L405 montre runt vient de ts->runtime[ddir]. Vous pouvez voir qu'il est initialisé par un appel à set_epoch_time() (https://github.com/axboe/fio/blob/6be06c46544c19e513ff80e7b841b1de688ffc66/backend.c#L1664), est mis à jour par update_runtime() (https://github.com/axboe/fio/blob/6be06c46544c19e513ff80e7b841b1de688ffc66/backend.c#L371) qui est appelé de thread_main().