[12177] | 1 | /* |
---|
| 2 | |
---|
| 3 | *************************************************************************************************** |
---|
| 4 | ** |
---|
| 5 | ** profile.cpp |
---|
| 6 | ** |
---|
| 7 | ** Real-Time Hierarchical Profiling for Game Programming Gems 3 |
---|
| 8 | ** |
---|
| 9 | ** by Greg Hjelstrom & Byon Garrabrant |
---|
| 10 | ** |
---|
| 11 | ***************************************************************************************************/ |
---|
| 12 | |
---|
| 13 | // Credits: The Clock class was inspired by the Timer classes in |
---|
| 14 | // Ogre (www.ogre3d.org). |
---|
| 15 | |
---|
| 16 | #include "btQuickprof.h" |
---|
| 17 | |
---|
| 18 | #ifndef BT_NO_PROFILE |
---|
| 19 | |
---|
| 20 | |
---|
| 21 | static btClock gProfileClock; |
---|
| 22 | |
---|
| 23 | |
---|
| 24 | #ifdef __CELLOS_LV2__ |
---|
| 25 | #include <sys/sys_time.h> |
---|
| 26 | #include <sys/time_util.h> |
---|
| 27 | #include <stdio.h> |
---|
| 28 | #endif |
---|
| 29 | |
---|
| 30 | #if defined (SUNOS) || defined (__SUNOS__) |
---|
| 31 | #include <stdio.h> |
---|
| 32 | #endif |
---|
| 33 | |
---|
| 34 | #if defined(WIN32) || defined(_WIN32) |
---|
| 35 | |
---|
| 36 | #define BT_USE_WINDOWS_TIMERS |
---|
| 37 | #define WIN32_LEAN_AND_MEAN |
---|
| 38 | #define NOWINRES |
---|
| 39 | #define NOMCX |
---|
| 40 | #define NOIME |
---|
| 41 | |
---|
| 42 | #ifdef _XBOX |
---|
| 43 | #include <Xtl.h> |
---|
| 44 | #else //_XBOX |
---|
| 45 | #include <windows.h> |
---|
| 46 | #endif //_XBOX |
---|
| 47 | |
---|
| 48 | #include <time.h> |
---|
| 49 | |
---|
| 50 | |
---|
| 51 | #else //_WIN32 |
---|
| 52 | #include <sys/time.h> |
---|
| 53 | #endif //_WIN32 |
---|
| 54 | |
---|
| 55 | #define mymin(a,b) (a > b ? a : b) |
---|
| 56 | |
---|
| 57 | struct btClockData |
---|
| 58 | { |
---|
| 59 | |
---|
| 60 | #ifdef BT_USE_WINDOWS_TIMERS |
---|
| 61 | LARGE_INTEGER mClockFrequency; |
---|
| 62 | DWORD mStartTick; |
---|
| 63 | LONGLONG mPrevElapsedTime; |
---|
| 64 | LARGE_INTEGER mStartTime; |
---|
| 65 | #else |
---|
| 66 | #ifdef __CELLOS_LV2__ |
---|
| 67 | uint64_t mStartTime; |
---|
| 68 | #else |
---|
| 69 | struct timeval mStartTime; |
---|
| 70 | #endif |
---|
| 71 | #endif //__CELLOS_LV2__ |
---|
| 72 | |
---|
| 73 | }; |
---|
| 74 | |
---|
| 75 | ///The btClock is a portable basic clock that measures accurate time in seconds, use for profiling. |
---|
| 76 | btClock::btClock() |
---|
| 77 | { |
---|
| 78 | m_data = new btClockData; |
---|
| 79 | #ifdef BT_USE_WINDOWS_TIMERS |
---|
| 80 | QueryPerformanceFrequency(&m_data->mClockFrequency); |
---|
| 81 | #endif |
---|
| 82 | reset(); |
---|
| 83 | } |
---|
| 84 | |
---|
| 85 | btClock::~btClock() |
---|
| 86 | { |
---|
| 87 | delete m_data; |
---|
| 88 | } |
---|
| 89 | |
---|
| 90 | btClock::btClock(const btClock& other) |
---|
| 91 | { |
---|
| 92 | m_data = new btClockData; |
---|
| 93 | *m_data = *other.m_data; |
---|
| 94 | } |
---|
| 95 | |
---|
| 96 | btClock& btClock::operator=(const btClock& other) |
---|
| 97 | { |
---|
| 98 | *m_data = *other.m_data; |
---|
| 99 | return *this; |
---|
| 100 | } |
---|
| 101 | |
---|
| 102 | |
---|
| 103 | /// Resets the initial reference time. |
---|
| 104 | void btClock::reset() |
---|
| 105 | { |
---|
| 106 | #ifdef BT_USE_WINDOWS_TIMERS |
---|
| 107 | QueryPerformanceCounter(&m_data->mStartTime); |
---|
| 108 | m_data->mStartTick = GetTickCount(); |
---|
| 109 | m_data->mPrevElapsedTime = 0; |
---|
| 110 | #else |
---|
| 111 | #ifdef __CELLOS_LV2__ |
---|
| 112 | |
---|
| 113 | typedef uint64_t ClockSize; |
---|
| 114 | ClockSize newTime; |
---|
| 115 | //__asm __volatile__( "mftb %0" : "=r" (newTime) : : "memory"); |
---|
| 116 | SYS_TIMEBASE_GET( newTime ); |
---|
| 117 | m_data->mStartTime = newTime; |
---|
| 118 | #else |
---|
| 119 | gettimeofday(&m_data->mStartTime, 0); |
---|
| 120 | #endif |
---|
| 121 | #endif |
---|
| 122 | } |
---|
| 123 | |
---|
| 124 | /// Returns the time in ms since the last call to reset or since |
---|
| 125 | /// the btClock was created. |
---|
| 126 | unsigned long int btClock::getTimeMilliseconds() |
---|
| 127 | { |
---|
| 128 | #ifdef BT_USE_WINDOWS_TIMERS |
---|
| 129 | LARGE_INTEGER currentTime; |
---|
| 130 | QueryPerformanceCounter(¤tTime); |
---|
| 131 | LONGLONG elapsedTime = currentTime.QuadPart - |
---|
| 132 | m_data->mStartTime.QuadPart; |
---|
| 133 | // Compute the number of millisecond ticks elapsed. |
---|
| 134 | unsigned long msecTicks = (unsigned long)(1000 * elapsedTime / |
---|
| 135 | m_data->mClockFrequency.QuadPart); |
---|
| 136 | // Check for unexpected leaps in the Win32 performance counter. |
---|
| 137 | // (This is caused by unexpected data across the PCI to ISA |
---|
| 138 | // bridge, aka south bridge. See Microsoft KB274323.) |
---|
| 139 | unsigned long elapsedTicks = GetTickCount() - m_data->mStartTick; |
---|
| 140 | signed long msecOff = (signed long)(msecTicks - elapsedTicks); |
---|
| 141 | if (msecOff < -100 || msecOff > 100) |
---|
| 142 | { |
---|
| 143 | // Adjust the starting time forwards. |
---|
| 144 | LONGLONG msecAdjustment = mymin(msecOff * |
---|
| 145 | m_data->mClockFrequency.QuadPart / 1000, elapsedTime - |
---|
| 146 | m_data->mPrevElapsedTime); |
---|
| 147 | m_data->mStartTime.QuadPart += msecAdjustment; |
---|
| 148 | elapsedTime -= msecAdjustment; |
---|
| 149 | |
---|
| 150 | // Recompute the number of millisecond ticks elapsed. |
---|
| 151 | msecTicks = (unsigned long)(1000 * elapsedTime / |
---|
| 152 | m_data->mClockFrequency.QuadPart); |
---|
| 153 | } |
---|
| 154 | |
---|
| 155 | // Store the current elapsed time for adjustments next time. |
---|
| 156 | m_data->mPrevElapsedTime = elapsedTime; |
---|
| 157 | |
---|
| 158 | return msecTicks; |
---|
| 159 | #else |
---|
| 160 | |
---|
| 161 | #ifdef __CELLOS_LV2__ |
---|
| 162 | uint64_t freq=sys_time_get_timebase_frequency(); |
---|
| 163 | double dFreq=((double) freq) / 1000.0; |
---|
| 164 | typedef uint64_t ClockSize; |
---|
| 165 | ClockSize newTime; |
---|
| 166 | SYS_TIMEBASE_GET( newTime ); |
---|
| 167 | //__asm __volatile__( "mftb %0" : "=r" (newTime) : : "memory"); |
---|
| 168 | |
---|
| 169 | return (unsigned long int)((double(newTime-m_data->mStartTime)) / dFreq); |
---|
| 170 | #else |
---|
| 171 | |
---|
| 172 | struct timeval currentTime; |
---|
| 173 | gettimeofday(¤tTime, 0); |
---|
| 174 | return (currentTime.tv_sec - m_data->mStartTime.tv_sec) * 1000 + |
---|
| 175 | (currentTime.tv_usec - m_data->mStartTime.tv_usec) / 1000; |
---|
| 176 | #endif //__CELLOS_LV2__ |
---|
| 177 | #endif |
---|
| 178 | } |
---|
| 179 | |
---|
| 180 | /// Returns the time in us since the last call to reset or since |
---|
| 181 | /// the Clock was created. |
---|
| 182 | unsigned long int btClock::getTimeMicroseconds() |
---|
| 183 | { |
---|
| 184 | #ifdef BT_USE_WINDOWS_TIMERS |
---|
| 185 | LARGE_INTEGER currentTime; |
---|
| 186 | QueryPerformanceCounter(¤tTime); |
---|
| 187 | LONGLONG elapsedTime = currentTime.QuadPart - |
---|
| 188 | m_data->mStartTime.QuadPart; |
---|
| 189 | |
---|
| 190 | // Compute the number of millisecond ticks elapsed. |
---|
| 191 | unsigned long msecTicks = (unsigned long)(1000 * elapsedTime / |
---|
| 192 | m_data->mClockFrequency.QuadPart); |
---|
| 193 | |
---|
| 194 | // Check for unexpected leaps in the Win32 performance counter. |
---|
| 195 | // (This is caused by unexpected data across the PCI to ISA |
---|
| 196 | // bridge, aka south bridge. See Microsoft KB274323.) |
---|
| 197 | unsigned long elapsedTicks = GetTickCount() - m_data->mStartTick; |
---|
| 198 | signed long msecOff = (signed long)(msecTicks - elapsedTicks); |
---|
| 199 | if (msecOff < -100 || msecOff > 100) |
---|
| 200 | { |
---|
| 201 | // Adjust the starting time forwards. |
---|
| 202 | LONGLONG msecAdjustment = mymin(msecOff * |
---|
| 203 | m_data->mClockFrequency.QuadPart / 1000, elapsedTime - |
---|
| 204 | m_data->mPrevElapsedTime); |
---|
| 205 | m_data->mStartTime.QuadPart += msecAdjustment; |
---|
| 206 | elapsedTime -= msecAdjustment; |
---|
| 207 | } |
---|
| 208 | |
---|
| 209 | // Store the current elapsed time for adjustments next time. |
---|
| 210 | m_data->mPrevElapsedTime = elapsedTime; |
---|
| 211 | |
---|
| 212 | // Convert to microseconds. |
---|
| 213 | unsigned long usecTicks = (unsigned long)(1000000 * elapsedTime / |
---|
| 214 | m_data->mClockFrequency.QuadPart); |
---|
| 215 | |
---|
| 216 | return usecTicks; |
---|
| 217 | #else |
---|
| 218 | |
---|
| 219 | #ifdef __CELLOS_LV2__ |
---|
| 220 | uint64_t freq=sys_time_get_timebase_frequency(); |
---|
| 221 | double dFreq=((double) freq)/ 1000000.0; |
---|
| 222 | typedef uint64_t ClockSize; |
---|
| 223 | ClockSize newTime; |
---|
| 224 | //__asm __volatile__( "mftb %0" : "=r" (newTime) : : "memory"); |
---|
| 225 | SYS_TIMEBASE_GET( newTime ); |
---|
| 226 | |
---|
| 227 | return (unsigned long int)((double(newTime-m_data->mStartTime)) / dFreq); |
---|
| 228 | #else |
---|
| 229 | |
---|
| 230 | struct timeval currentTime; |
---|
| 231 | gettimeofday(¤tTime, 0); |
---|
| 232 | return (currentTime.tv_sec - m_data->mStartTime.tv_sec) * 1000000 + |
---|
| 233 | (currentTime.tv_usec - m_data->mStartTime.tv_usec); |
---|
| 234 | #endif//__CELLOS_LV2__ |
---|
| 235 | #endif |
---|
| 236 | } |
---|
| 237 | |
---|
| 238 | |
---|
| 239 | |
---|
| 240 | |
---|
| 241 | |
---|
| 242 | inline void Profile_Get_Ticks(unsigned long int * ticks) |
---|
| 243 | { |
---|
| 244 | *ticks = gProfileClock.getTimeMicroseconds(); |
---|
| 245 | } |
---|
| 246 | |
---|
| 247 | inline float Profile_Get_Tick_Rate(void) |
---|
| 248 | { |
---|
| 249 | // return 1000000.f; |
---|
| 250 | return 1000.f; |
---|
| 251 | |
---|
| 252 | } |
---|
| 253 | |
---|
| 254 | |
---|
| 255 | |
---|
| 256 | /*************************************************************************************************** |
---|
| 257 | ** |
---|
| 258 | ** CProfileNode |
---|
| 259 | ** |
---|
| 260 | ***************************************************************************************************/ |
---|
| 261 | |
---|
| 262 | /*********************************************************************************************** |
---|
| 263 | * INPUT: * |
---|
| 264 | * name - pointer to a static string which is the name of this profile node * |
---|
| 265 | * parent - parent pointer * |
---|
| 266 | * * |
---|
| 267 | * WARNINGS: * |
---|
| 268 | * The name is assumed to be a static pointer, only the pointer is stored and compared for * |
---|
| 269 | * efficiency reasons. * |
---|
| 270 | *=============================================================================================*/ |
---|
| 271 | CProfileNode::CProfileNode( const char * name, CProfileNode * parent ) : |
---|
| 272 | Name( name ), |
---|
| 273 | TotalCalls( 0 ), |
---|
| 274 | TotalTime( 0 ), |
---|
| 275 | StartTime( 0 ), |
---|
| 276 | RecursionCounter( 0 ), |
---|
| 277 | Parent( parent ), |
---|
| 278 | Child( NULL ), |
---|
| 279 | Sibling( NULL ) |
---|
| 280 | { |
---|
| 281 | Reset(); |
---|
| 282 | } |
---|
| 283 | |
---|
| 284 | |
---|
| 285 | void CProfileNode::CleanupMemory() |
---|
| 286 | { |
---|
| 287 | delete ( Child); |
---|
| 288 | Child = NULL; |
---|
| 289 | delete ( Sibling); |
---|
| 290 | Sibling = NULL; |
---|
| 291 | } |
---|
| 292 | |
---|
| 293 | CProfileNode::~CProfileNode( void ) |
---|
| 294 | { |
---|
| 295 | delete ( Child); |
---|
| 296 | delete ( Sibling); |
---|
| 297 | } |
---|
| 298 | |
---|
| 299 | |
---|
| 300 | /*********************************************************************************************** |
---|
| 301 | * INPUT: * |
---|
| 302 | * name - static string pointer to the name of the node we are searching for * |
---|
| 303 | * * |
---|
| 304 | * WARNINGS: * |
---|
| 305 | * All profile names are assumed to be static strings so this function uses pointer compares * |
---|
| 306 | * to find the named node. * |
---|
| 307 | *=============================================================================================*/ |
---|
| 308 | CProfileNode * CProfileNode::Get_Sub_Node( const char * name ) |
---|
| 309 | { |
---|
| 310 | // Try to find this sub node |
---|
| 311 | CProfileNode * child = Child; |
---|
| 312 | while ( child ) { |
---|
| 313 | if ( child->Name == name ) { |
---|
| 314 | return child; |
---|
| 315 | } |
---|
| 316 | child = child->Sibling; |
---|
| 317 | } |
---|
| 318 | |
---|
| 319 | // We didn't find it, so add it |
---|
| 320 | |
---|
| 321 | CProfileNode * node = new CProfileNode( name, this ); |
---|
| 322 | node->Sibling = Child; |
---|
| 323 | Child = node; |
---|
| 324 | return node; |
---|
| 325 | } |
---|
| 326 | |
---|
| 327 | |
---|
| 328 | void CProfileNode::Reset( void ) |
---|
| 329 | { |
---|
| 330 | TotalCalls = 0; |
---|
| 331 | TotalTime = 0.0f; |
---|
| 332 | |
---|
| 333 | |
---|
| 334 | if ( Child ) { |
---|
| 335 | Child->Reset(); |
---|
| 336 | } |
---|
| 337 | if ( Sibling ) { |
---|
| 338 | Sibling->Reset(); |
---|
| 339 | } |
---|
| 340 | } |
---|
| 341 | |
---|
| 342 | |
---|
| 343 | void CProfileNode::Call( void ) |
---|
| 344 | { |
---|
| 345 | TotalCalls++; |
---|
| 346 | if (RecursionCounter++ == 0) { |
---|
| 347 | Profile_Get_Ticks(&StartTime); |
---|
| 348 | } |
---|
| 349 | } |
---|
| 350 | |
---|
| 351 | |
---|
| 352 | bool CProfileNode::Return( void ) |
---|
| 353 | { |
---|
| 354 | if ( --RecursionCounter == 0 && TotalCalls != 0 ) { |
---|
| 355 | unsigned long int time; |
---|
| 356 | Profile_Get_Ticks(&time); |
---|
| 357 | time-=StartTime; |
---|
| 358 | TotalTime += (float)time / Profile_Get_Tick_Rate(); |
---|
| 359 | } |
---|
| 360 | return ( RecursionCounter == 0 ); |
---|
| 361 | } |
---|
| 362 | |
---|
| 363 | |
---|
| 364 | /*************************************************************************************************** |
---|
| 365 | ** |
---|
| 366 | ** CProfileIterator |
---|
| 367 | ** |
---|
| 368 | ***************************************************************************************************/ |
---|
| 369 | CProfileIterator::CProfileIterator( CProfileNode * start ) |
---|
| 370 | { |
---|
| 371 | CurrentParent = start; |
---|
| 372 | CurrentChild = CurrentParent->Get_Child(); |
---|
| 373 | } |
---|
| 374 | |
---|
| 375 | |
---|
| 376 | void CProfileIterator::First(void) |
---|
| 377 | { |
---|
| 378 | CurrentChild = CurrentParent->Get_Child(); |
---|
| 379 | } |
---|
| 380 | |
---|
| 381 | |
---|
| 382 | void CProfileIterator::Next(void) |
---|
| 383 | { |
---|
| 384 | CurrentChild = CurrentChild->Get_Sibling(); |
---|
| 385 | } |
---|
| 386 | |
---|
| 387 | |
---|
| 388 | bool CProfileIterator::Is_Done(void) |
---|
| 389 | { |
---|
| 390 | return CurrentChild == NULL; |
---|
| 391 | } |
---|
| 392 | |
---|
| 393 | |
---|
| 394 | void CProfileIterator::Enter_Child( int index ) |
---|
| 395 | { |
---|
| 396 | CurrentChild = CurrentParent->Get_Child(); |
---|
| 397 | while ( (CurrentChild != NULL) && (index != 0) ) { |
---|
| 398 | index--; |
---|
| 399 | CurrentChild = CurrentChild->Get_Sibling(); |
---|
| 400 | } |
---|
| 401 | |
---|
| 402 | if ( CurrentChild != NULL ) { |
---|
| 403 | CurrentParent = CurrentChild; |
---|
| 404 | CurrentChild = CurrentParent->Get_Child(); |
---|
| 405 | } |
---|
| 406 | } |
---|
| 407 | |
---|
| 408 | |
---|
| 409 | void CProfileIterator::Enter_Parent( void ) |
---|
| 410 | { |
---|
| 411 | if ( CurrentParent->Get_Parent() != NULL ) { |
---|
| 412 | CurrentParent = CurrentParent->Get_Parent(); |
---|
| 413 | } |
---|
| 414 | CurrentChild = CurrentParent->Get_Child(); |
---|
| 415 | } |
---|
| 416 | |
---|
| 417 | |
---|
| 418 | /*************************************************************************************************** |
---|
| 419 | ** |
---|
| 420 | ** CProfileManager |
---|
| 421 | ** |
---|
| 422 | ***************************************************************************************************/ |
---|
| 423 | |
---|
| 424 | CProfileNode CProfileManager::Root( "Root", NULL ); |
---|
| 425 | CProfileNode * CProfileManager::CurrentNode = &CProfileManager::Root; |
---|
| 426 | int CProfileManager::FrameCounter = 0; |
---|
| 427 | unsigned long int CProfileManager::ResetTime = 0; |
---|
| 428 | |
---|
| 429 | |
---|
| 430 | /*********************************************************************************************** |
---|
| 431 | * CProfileManager::Start_Profile -- Begin a named profile * |
---|
| 432 | * * |
---|
| 433 | * Steps one level deeper into the tree, if a child already exists with the specified name * |
---|
| 434 | * then it accumulates the profiling; otherwise a new child node is added to the profile tree. * |
---|
| 435 | * * |
---|
| 436 | * INPUT: * |
---|
| 437 | * name - name of this profiling record * |
---|
| 438 | * * |
---|
| 439 | * WARNINGS: * |
---|
| 440 | * The string used is assumed to be a static string; pointer compares are used throughout * |
---|
| 441 | * the profiling code for efficiency. * |
---|
| 442 | *=============================================================================================*/ |
---|
| 443 | void CProfileManager::Start_Profile( const char * name ) |
---|
| 444 | { |
---|
| 445 | if (name != CurrentNode->Get_Name()) { |
---|
| 446 | CurrentNode = CurrentNode->Get_Sub_Node( name ); |
---|
| 447 | } |
---|
| 448 | |
---|
| 449 | CurrentNode->Call(); |
---|
| 450 | } |
---|
| 451 | |
---|
| 452 | |
---|
| 453 | /*********************************************************************************************** |
---|
| 454 | * CProfileManager::Stop_Profile -- Stop timing and record the results. * |
---|
| 455 | *=============================================================================================*/ |
---|
| 456 | void CProfileManager::Stop_Profile( void ) |
---|
| 457 | { |
---|
| 458 | // Return will indicate whether we should back up to our parent (we may |
---|
| 459 | // be profiling a recursive function) |
---|
| 460 | if (CurrentNode->Return()) { |
---|
| 461 | CurrentNode = CurrentNode->Get_Parent(); |
---|
| 462 | } |
---|
| 463 | } |
---|
| 464 | |
---|
| 465 | |
---|
| 466 | /*********************************************************************************************** |
---|
| 467 | * CProfileManager::Reset -- Reset the contents of the profiling system * |
---|
| 468 | * * |
---|
| 469 | * This resets everything except for the tree structure. All of the timing data is reset. * |
---|
| 470 | *=============================================================================================*/ |
---|
| 471 | void CProfileManager::Reset( void ) |
---|
| 472 | { |
---|
| 473 | gProfileClock.reset(); |
---|
| 474 | Root.Reset(); |
---|
| 475 | Root.Call(); |
---|
| 476 | FrameCounter = 0; |
---|
| 477 | Profile_Get_Ticks(&ResetTime); |
---|
| 478 | } |
---|
| 479 | |
---|
| 480 | |
---|
| 481 | /*********************************************************************************************** |
---|
| 482 | * CProfileManager::Increment_Frame_Counter -- Increment the frame counter * |
---|
| 483 | *=============================================================================================*/ |
---|
| 484 | void CProfileManager::Increment_Frame_Counter( void ) |
---|
| 485 | { |
---|
| 486 | FrameCounter++; |
---|
| 487 | } |
---|
| 488 | |
---|
| 489 | |
---|
| 490 | /*********************************************************************************************** |
---|
| 491 | * CProfileManager::Get_Time_Since_Reset -- returns the elapsed time since last reset * |
---|
| 492 | *=============================================================================================*/ |
---|
| 493 | float CProfileManager::Get_Time_Since_Reset( void ) |
---|
| 494 | { |
---|
| 495 | unsigned long int time; |
---|
| 496 | Profile_Get_Ticks(&time); |
---|
| 497 | time -= ResetTime; |
---|
| 498 | return (float)time / Profile_Get_Tick_Rate(); |
---|
| 499 | } |
---|
| 500 | |
---|
| 501 | #include <stdio.h> |
---|
| 502 | |
---|
| 503 | void CProfileManager::dumpRecursive(CProfileIterator* profileIterator, int spacing) |
---|
| 504 | { |
---|
| 505 | profileIterator->First(); |
---|
| 506 | if (profileIterator->Is_Done()) |
---|
| 507 | return; |
---|
| 508 | |
---|
| 509 | float accumulated_time=0,parent_time = profileIterator->Is_Root() ? CProfileManager::Get_Time_Since_Reset() : profileIterator->Get_Current_Parent_Total_Time(); |
---|
| 510 | int i; |
---|
| 511 | int frames_since_reset = CProfileManager::Get_Frame_Count_Since_Reset(); |
---|
| 512 | for (i=0;i<spacing;i++) printf("."); |
---|
| 513 | printf("----------------------------------\n"); |
---|
| 514 | for (i=0;i<spacing;i++) printf("."); |
---|
| 515 | printf("Profiling: %s (total running time: %.3f ms) ---\n", profileIterator->Get_Current_Parent_Name(), parent_time ); |
---|
| 516 | float totalTime = 0.f; |
---|
| 517 | |
---|
| 518 | |
---|
| 519 | int numChildren = 0; |
---|
| 520 | |
---|
| 521 | for (i = 0; !profileIterator->Is_Done(); i++,profileIterator->Next()) |
---|
| 522 | { |
---|
| 523 | numChildren++; |
---|
| 524 | float current_total_time = profileIterator->Get_Current_Total_Time(); |
---|
| 525 | accumulated_time += current_total_time; |
---|
| 526 | float fraction = parent_time > SIMD_EPSILON ? (current_total_time / parent_time) * 100 : 0.f; |
---|
| 527 | { |
---|
| 528 | int i; for (i=0;i<spacing;i++) printf("."); |
---|
| 529 | } |
---|
| 530 | printf("%d -- %s (%.2f %%) :: %.3f ms / frame (%d calls)\n",i, profileIterator->Get_Current_Name(), fraction,(current_total_time / (double)frames_since_reset),profileIterator->Get_Current_Total_Calls()); |
---|
| 531 | totalTime += current_total_time; |
---|
| 532 | //recurse into children |
---|
| 533 | } |
---|
| 534 | |
---|
| 535 | if (parent_time < accumulated_time) |
---|
| 536 | { |
---|
| 537 | printf("what's wrong\n"); |
---|
| 538 | } |
---|
| 539 | for (i=0;i<spacing;i++) printf("."); |
---|
| 540 | printf("%s (%.3f %%) :: %.3f ms\n", "Unaccounted:",parent_time > SIMD_EPSILON ? ((parent_time - accumulated_time) / parent_time) * 100 : 0.f, parent_time - accumulated_time); |
---|
| 541 | |
---|
| 542 | for (i=0;i<numChildren;i++) |
---|
| 543 | { |
---|
| 544 | profileIterator->Enter_Child(i); |
---|
| 545 | dumpRecursive(profileIterator,spacing+3); |
---|
| 546 | profileIterator->Enter_Parent(); |
---|
| 547 | } |
---|
| 548 | } |
---|
| 549 | |
---|
| 550 | |
---|
| 551 | |
---|
| 552 | void CProfileManager::dumpAll() |
---|
| 553 | { |
---|
| 554 | CProfileIterator* profileIterator = 0; |
---|
| 555 | profileIterator = CProfileManager::Get_Iterator(); |
---|
| 556 | |
---|
| 557 | dumpRecursive(profileIterator,0); |
---|
| 558 | |
---|
| 559 | CProfileManager::Release_Iterator(profileIterator); |
---|
| 560 | } |
---|
| 561 | |
---|
| 562 | |
---|
| 563 | |
---|
| 564 | |
---|
| 565 | #endif //BT_NO_PROFILE |
---|