Mesurer le temps CPU sur une machine multicoeurs

Bonjour,

lorsque je travaillais en C, je mesurais le temps CPU consommé par mes algorithmes avec un bout de code ressemblant à peu de choses près à ceci

Code:

---

1 2 3 4 5 6 7 8 9 10

#include <time.h>   clock_t start, end; double cpu_time_used;   start = clock(); ... /* Do the work. */ end = clock(); cpu_time_used = ((double) (end - start)) / CLOCKS_PER_SEC;

---

J'ai depuis acquis un calculateur à 4 coeurs et la valeur retournée à présent par ces lignes est excessivement élevée.
Pour l'instant, j'ai réussi à contourner le problème en faisant appel à la routine Fortran CPU_TIME, qui elle fonctionne toujours de la même manière sur ma machine.
Savez-vous comment mesurer le temps CPU en C++ sur des architectures parallèles (i.e. sans mixer avec du Fortran ou un autre langage)?

Bonjour,
Pour ca j'utilise boost::timer, qui est portable, et bien plus précis que clock()

Bonjour,

merci pour ta réponse Nogane.
Sais-tu si le temps écoulé mesuré avec boost::timer est du temps CPU?

Tout compte fait il semblerais que boost::timer utilise std::clock, donc ce n'est pas une bonne piste.

regarde du coté de boost::chrono. Sinon gettimeofday/QueryPerformanceCoutner ou rdtsc

Effectivement boost::timer est loin d'être le plus précis, boost::chrono semble être la bonne alternative mais n'est pas encore fini si j'ai bien compris.

Concernant le jonglage de cpu, une des techniques pour s'assurer que le temps est correct est de forcer le code qui récupère le temps a se faire executer toujours par le même unit.
Les gens de chez Ogre ont du code portable qui gère le cas des multi-core (parcequ'il y avait des sautes de timers quand le thread changeait de core d'execution).
Voici les sources pour windows : http://bitbucket.org/hef/ogre/src/ti.../OgreTimer.cpp

Si tu remontes dans l'arborescence tu verras les implementations pour divers autres OS donc Mac et Linux.

Merci pour ta réponse Klaim.
Le lien que tu donnes renvoie à ceci :

Code:

---

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212

/* ----------------------------------------------------------------------------- This source file is part of OGRE   (Object-oriented Graphics Rendering Engine) For the latest info, see http://www.ogre3d.org/   Copyright (c) 2000-2009 Torus Knot Software Ltd   Permission is hereby granted, free of charge, to any person obtaining a copy of this software and associated documentation files (the "Software"), to deal in the Software without restriction, including without limitation the rights to use, copy, modify, merge, publish, distribute, sublicense, and/or sell copies of the Software, and to permit persons to whom the Software is furnished to do so, subject to the following conditions:   The above copyright notice and this permission notice shall be included in all copies or substantial portions of the Software.   THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. ----------------------------------------------------------------------------- */ #include "OgreStableHeaders.h" #include "OgreTimer.h" #include "OgreBitwise.h"   using namespace Ogre;   //------------------------------------------------------------------------- Timer::Timer() : mTimerMask( 0 ) { reset(); }   //------------------------------------------------------------------------- Timer::~Timer() { }   //------------------------------------------------------------------------- bool Timer::setOption( const String & key, const void * val ) { if ( key == "QueryAffinityMask" ) { // Telling timer what core to use for a timer read DWORD newTimerMask = * static_cast < const DWORD * > ( val );   // Get the current process core mask DWORD_PTR procMask; DWORD_PTR sysMask; GetProcessAffinityMask(GetCurrentProcess(), &procMask, &sysMask);   // If new mask is 0, then set to default behavior, otherwise check // to make sure new timer core mask overlaps with process core mask // and that new timer core mask is a power of 2 (i.e. a single core) if( ( newTimerMask == 0 ) || ( ( ( newTimerMask & procMask ) != 0 ) && Bitwise::isPO2( newTimerMask ) ) ) { mTimerMask = newTimerMask; return true; } }   return false; }   //------------------------------------------------------------------------- void Timer::reset() { // Get the current process core mask DWORD_PTR procMask; DWORD_PTR sysMask; GetProcessAffinityMask(GetCurrentProcess(), &procMask, &sysMask);   // If procMask is 0, consider there is only one core available // (using 0 as procMask will cause an infinite loop below) if (procMask == 0) procMask = 1;   // Find the lowest core that this process uses if( mTimerMask == 0 ) { mTimerMask = 1; while( ( mTimerMask & procMask ) == 0 ) { mTimerMask <<= 1; } }   HANDLE thread = GetCurrentThread();   // Set affinity to the first core DWORD_PTR oldMask = SetThreadAffinityMask(thread, mTimerMask);   // Get the constant frequency QueryPerformanceFrequency(&mFrequency);   // Query the timer QueryPerformanceCounter(&mStartTime); mStartTick = GetTickCount();   // Reset affinity SetThreadAffinityMask(thread, oldMask);   mLastTime = 0; mZeroClock = clock(); }   //------------------------------------------------------------------------- unsigned long Timer::getMilliseconds() { LARGE_INTEGER curTime;   HANDLE thread = GetCurrentThread();   // Set affinity to the first core DWORD_PTR oldMask = SetThreadAffinityMask(thread, mTimerMask);   // Query the timer QueryPerformanceCounter(&curTime);   // Reset affinity SetThreadAffinityMask(thread, oldMask);   LONGLONG newTime = curTime.QuadPart - mStartTime.QuadPart;   // scale by 1000 for milliseconds unsigned long newTicks = (unsigned long) (1000 * newTime / mFrequency.QuadPart);   // detect and compensate for performance counter leaps // (surprisingly common, see Microsoft KB: Q274323) unsigned long check = GetTickCount() - mStartTick; signed long msecOff = (signed long)(newTicks - check); if (msecOff < -100 || msecOff > 100) { // We must keep the timer running forward :) LONGLONG adjust = (std::min)(msecOff * mFrequency.QuadPart / 1000, newTime - mLastTime); mStartTime.QuadPart += adjust; newTime -= adjust;   // Re-calculate milliseconds newTicks = (unsigned long) (1000 * newTime / mFrequency.QuadPart); }   // Record last time for adjust mLastTime = newTime;   return newTicks; }   //------------------------------------------------------------------------- unsigned long Timer::getMicroseconds() { LARGE_INTEGER curTime;   HANDLE thread = GetCurrentThread();   // Set affinity to the first core DWORD_PTR oldMask = SetThreadAffinityMask(thread, mTimerMask);   // Query the timer QueryPerformanceCounter(&curTime);   // Reset affinity SetThreadAffinityMask(thread, oldMask);   LONGLONG newTime = curTime.QuadPart - mStartTime.QuadPart;   // get milliseconds to check against GetTickCount unsigned long newTicks = (unsigned long) (1000 * newTime / mFrequency.QuadPart);   // detect and compensate for performance counter leaps // (surprisingly common, see Microsoft KB: Q274323) unsigned long check = GetTickCount() - mStartTick; signed long msecOff = (signed long)(newTicks - check); if (msecOff < -100 || msecOff > 100) { // We must keep the timer running forward :) LONGLONG adjust = (std::min)(msecOff * mFrequency.QuadPart / 1000, newTime - mLastTime); mStartTime.QuadPart += adjust; newTime -= adjust; }   // Record last time for adjust mLastTime = newTime;   // scale by 1000000 for microseconds unsigned long newMicro = (unsigned long) (1000000 * newTime / mFrequency.QuadPart);   return newMicro; }   //------------------------------------------------------------------------- unsigned long Timer::getMillisecondsCPU() { clock_t newClock = clock(); return (unsigned long)( (float)( newClock - mZeroClock ) / ( (float)CLOCKS_PER_SEC / 1000.0 ) ) ; }   //------------------------------------------------------------------------- unsigned long Timer::getMicrosecondsCPU() { clock_t newClock = clock(); return (unsigned long)( (float)( newClock - mZeroClock ) / ( (float)CLOCKS_PER_SEC / 1000000.0 ) ) ; }

---

Sauf erreur de ma part, la fonction getMillisecondsCPU() correspond à l'implémentation classique dont je parle dans mon message initial :

Code:

---

1 2 3 4 5 6

unsigned long Timer::getMillisecondsCPU() { clock_t newClock = clock(); return (unsigned long)( (float)( newClock - mZeroClock ) / ( (float)CLOCKS_PER_SEC / 1000.0 ) ) ; }

---

Tu écris

Citation:

---

Concernant le jonglage de cpu, une des techniques pour s'assurer que le temps est correct est de forcer le code qui récupère le temps a se faire executer toujours par le même unit.

---

J'imagine que pour faire cela, je dois appeler la fonction

Code:

---

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41

unsigned long Timer::getMilliseconds() { LARGE_INTEGER curTime;   HANDLE thread = GetCurrentThread();   // Set affinity to the first core DWORD_PTR oldMask = SetThreadAffinityMask(thread, mTimerMask);   // Query the timer QueryPerformanceCounter(&curTime);   // Reset affinity SetThreadAffinityMask(thread, oldMask);   LONGLONG newTime = curTime.QuadPart - mStartTime.QuadPart;   // scale by 1000 for milliseconds unsigned long newTicks = (unsigned long) (1000 * newTime / mFrequency.QuadPart);   // detect and compensate for performance counter leaps // (surprisingly common, see Microsoft KB: Q274323) unsigned long check = GetTickCount() - mStartTick; signed long msecOff = (signed long)(newTicks - check); if (msecOff < -100 || msecOff > 100) { // We must keep the timer running forward :) LONGLONG adjust = (std::min)(msecOff * mFrequency.QuadPart / 1000, newTime - mLastTime); mStartTime.QuadPart += adjust; newTime -= adjust;   // Re-calculate milliseconds newTicks = (unsigned long) (1000 * newTime / mFrequency.QuadPart); }   // Record last time for adjust mLastTime = newTime;   return newTicks; }

---

Je ne vois pas le lien entre les deux fonctions...

Effectivement getTimeMilliseconds() est plus précis et est utilisé dans Ogre. Je ne me souviens plus pourquoi ils fournissaient getTimeMillisecondsCPU() exactement mais il est convenu que ce temps-ci est moins précis et fournis par l'api "classique".

Les commentaires sur l'interface ne sont pas très explicites malheureusement :

Code:

---

1 2 3 4 5 6 7 8 9 10 11

/** Returns milliseconds since initialisation or last reset */ unsigned long getMilliseconds();   /** Returns microseconds since initialisation or last reset */ unsigned long getMicroseconds();   /** Returns milliseconds since initialisation or last reset, only CPU time measured */ unsigned long getMillisecondsCPU();   /** Returns microseconds since initialisation or last reset, only CPU time measured */ unsigned long getMicrosecondsCPU();

---

Seules les fonction non-CPU sont utiles dans notre cas.

Merci Klaim.
J'ai tenté une première approche naïve.
J'ai fait une fonction cputime,

Code:

---

1 2 3 4 5 6 7 8 9 10 11 12 13 14

#include "cputime.hpp"   LONGLONG cputime() { LARGE_INTEGER curTime;   HANDLE thread = GetCurrentThread();   QueryPerformanceCounter(&curTime);     return curTime.QuadPart; }

---

que j'utilise comme ceci :

Code:

---

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22

#include <cstddef> #include <iostream> #include "cputime.hpp" /*  *  */ int main(int argc, char** argv) {   LARGE_INTEGER freq; LONGLONG tic = cputime(); // get current cputime for (size_t i=0;i<200000;++i){ for (size_t j=0;j<20000;++j) ; } LONGLONG toc = cputime(); // get current cputime QueryPerformanceFrequency(&freq); // get frequency double elapsedTime = (toc - tic)*1.0/ freq.QuadPart; std::cout<<elapsedTime<<std::endl;   return (EXIT_SUCCESS); }

---

Les valeurs que prend elapsedTime semblent avoir du sens mais je ne suis pas sûr de ce que je manipule (en particulier ce que contient freq).
J'ai également remarqué qu'un ajustement du temps est effectué dans les fonctions de Ogre (getMilliseconds et getMicroseconds).
Est-ce que tu saurais pourquoi?
Je suis allé voir l'article cité dans les commentaires mais je n'y comprends absolument rien.

La première partie du code de ces fonctions fixe l'affinité du thread a un core précis, appelle QueryPerformanceCounter puis remet l'affinité originale du thread. Cela permet d'éviter les décalages de compte de ticks qui sont légèrements différents selon les coeurs d'execution. On force le code qui récupère la valeur de tick à ne le faire à chaque fois que sur un coeur précis, pas sur "celui en cours" parcequ'il peut avoir changé.
Tu ne pourras pas voir le problème si ton application monothread et n'est pas balladée entre plusieurs cores (souvent parceque l'os équilibre les charges à sa manière) mais j'ai déjà vu les problèmes que ça peut poser et c'est assez déroutant quand c'est du code graphique par exemple.

Ensuite les calculs effectués sont relatif au compte du temps, rapport tick/temps.

Le test effectué avec ce commentaire :

Citation:

---

// detect and compensate for performance counter leaps
// (surprisingly common, see Microsoft KB: Q274323)

---

Comme indiqué dans le descriptif enanglais du problème, il y a une sorte de bug(?) qui fait que la fonction retourne parfois des valeures trop avancées dans le temps, fait des "bonds dans le temps". Du coup pour compenser ils utilisent une boucle qui corrige le temps passé en la maintenant à une "distance" par rapport à la dernière mise à jour qui soit plus "logique". Pour cela ils commencent par détecter qu'il y a eu un saut si le temps passé est plus long que ce qui est garanti par la fonction (ou le processeur?).