profiler.cpp
Engine/source/platform/profiler.cpp
Detailed Description
1 2//----------------------------------------------------------------------------- 3// Copyright (c) 2012 GarageGames, LLC 4// 5// Permission is hereby granted, free of charge, to any person obtaining a copy 6// of this software and associated documentation files (the "Software"), to 7// deal in the Software without restriction, including without limitation the 8// rights to use, copy, modify, merge, publish, distribute, sublicense, and/or 9// sell copies of the Software, and to permit persons to whom the Software is 10// furnished to do so, subject to the following conditions: 11// 12// The above copyright notice and this permission notice shall be included in 13// all copies or substantial portions of the Software. 14// 15// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR 16// IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, 17// FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE 18// AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER 19// LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING 20// FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS 21// IN THE SOFTWARE. 22//----------------------------------------------------------------------------- 23 24#include "platform/platform.h" 25 26#if defined(TORQUE_OS_WIN) 27#include<Windows.h> // for SetThreadAffinityMask, QueryPerformanceCounter, QueryPerformanceFrequency 28#elif defined(TORQUE_OS_MAC) 29#include <mach/mach_time.h> // for mach_absolute_time, mach_timebase_info 30#endif 31 32#include "core/stream/fileStream.h" 33#include "core/frameAllocator.h" 34#include "core/strings/stringFunctions.h" 35#include "core/stringTable.h" 36 37#include "platform/profiler.h" 38#include "platform/threads/thread.h" 39 40#include "console/engineAPI.h" 41 42#ifdef TORQUE_ENABLE_PROFILER 43ProfilerRootData *ProfilerRootData::sRootList = NULL; 44Profiler *gProfiler = NULL; 45 46// Uncomment the following line to enable a debugging aid for mismatched profiler blocks. 47//#define TORQUE_PROFILER_DEBUG 48 49// Machinery to record the stack of node names, as a debugging aid to find 50// mismatched PROFILE_START and PROFILE_END blocks. We profile from the 51// beginning to catch profile block errors that occur when torque is starting up. 52#ifdef TORQUE_PROFILER_DEBUG 53Vector<StringTableEntry> gProfilerNodeStack; 54#define TORQUE_PROFILE_AT_ENGINE_START true 55#define PROFILER_DEBUG_PUSH_NODE( nodename ) \ 56 gProfilerNodeStack.push_back( nodename ); 57#define PROFILER_DEBUG_POP_NODE() \ 58 gProfilerNodeStack.pop_back(); 59#else 60#define TORQUE_PROFILE_AT_ENGINE_START false 61#define PROFILER_DEBUG_PUSH_NODE( nodename ) ; 62#define PROFILER_DEBUG_POP_NODE() ; 63#endif 64 65#if defined(TORQUE_OS_WIN) 66 67static bool sQueryPerformanceInit = false; 68static U64 sQueryPerformanceFrequency = 0; 69 70// platform specific get hires times... 71void startHighResolutionTimer(U64 &time) 72{ 73 QueryPerformanceCounter((LARGE_INTEGER*)&time); 74} 75 76F64 endHighResolutionTimer(U64 time) 77{ 78 if (!sQueryPerformanceInit) 79 { 80 sQueryPerformanceInit = true; 81 QueryPerformanceFrequency((LARGE_INTEGER*)&sQueryPerformanceFrequency); 82 } 83 84 U64 current; 85 QueryPerformanceCounter((LARGE_INTEGER*)¤t); 86 87 return ((1000.0 * static_cast<F64>(current-time)) / static_cast<F64>(sQueryPerformanceFrequency)); 88} 89 90#elif defined(TORQUE_OS_MAC) 91 92void startHighResolutionTimer(U64 &time) { 93 time = mach_absolute_time(); 94} 95 96F64 endHighResolutionTimer(U64 time) { 97 static mach_timebase_info_data_t sTimebaseInfo = {0, 0}; 98 99 U64 now = mach_absolute_time(); 100 101 if(sTimebaseInfo.denom == 0){ 102 mach_timebase_info(&sTimebaseInfo); 103 } 104 // Handle the micros/nanos conversion first, because shedding a few bits is better than overflowing. 105 F64 elapsedMicros = (static_cast<F64>(now - time) / 1000.0) * static_cast<F64>(sTimebaseInfo.numer) / static_cast<F64>(sTimebaseInfo.denom); 106 107 return elapsedMicros; // Just truncate, and hope we didn't overflow 108} 109 110#else 111 112void startHighResolutionTimer(U64 &time) 113{ 114 time = (U64)Platform::getRealMilliseconds(); 115} 116 117F64 endHighResolutionTimer(U64 time) 118{ 119 return (F64)Platform::getRealMilliseconds() - time; 120} 121 122#endif 123 124Profiler::Profiler() 125{ 126 mMaxStackDepth = MaxStackDepth; 127 mCurrentHash = 0; 128 129 mCurrentProfilerData = (ProfilerData *) malloc(sizeof(ProfilerData)); 130 mCurrentProfilerData->mRoot = NULL; 131 mCurrentProfilerData->mNextForRoot = NULL; 132 mCurrentProfilerData->mNextProfilerData = NULL; 133 mCurrentProfilerData->mNextHash = NULL; 134 mCurrentProfilerData->mParent = NULL; 135 mCurrentProfilerData->mNextSibling = NULL; 136 mCurrentProfilerData->mFirstChild = NULL; 137 mCurrentProfilerData->mLastSeenProfiler = NULL; 138 mCurrentProfilerData->mHash = 0; 139 mCurrentProfilerData->mSubDepth = 0; 140 mCurrentProfilerData->mInvokeCount = 0; 141 mCurrentProfilerData->mTotalTime = 0; 142 mCurrentProfilerData->mSubTime = 0; 143#ifdef TORQUE_ENABLE_PROFILE_PATH 144 mCurrentProfilerData->mPath = ""; 145#endif 146 mRootProfilerData = mCurrentProfilerData; 147 148 for(U32 i = 0; i < ProfilerData::HashTableSize; i++) 149 mCurrentProfilerData->mChildHash[i] = 0; 150 151 mProfileList = NULL; 152 153 mEnabled = TORQUE_PROFILE_AT_ENGINE_START; 154 mNextEnable = TORQUE_PROFILE_AT_ENGINE_START; 155 mStackDepth = 0; 156 gProfiler = this; 157 mDumpToConsole = false; 158 mDumpToFile = false; 159 mDumpFileName[0] = '\0'; 160} 161 162Profiler::~Profiler() 163{ 164 reset(); 165 free(mRootProfilerData); 166 gProfiler = NULL; 167} 168 169void Profiler::reset() 170{ 171 mEnabled = false; // in case we're in a profiler call. 172 ProfilerData * head = mProfileList; 173 ProfilerData * curr = head; 174 175 while ( curr ) 176 { 177 head = curr->mNextProfilerData; 178 free( curr ); 179 180 if ( head ) 181 curr = head; 182 else 183 curr = NULL; 184 } 185 186 mProfileList = NULL; 187 188 for(ProfilerRootData *walk = ProfilerRootData::sRootList; walk; walk = walk->mNextRoot) 189 { 190 walk->mFirstProfilerData = 0; 191 walk->mTotalTime = 0; 192 walk->mSubTime = 0; 193 walk->mTotalInvokeCount = 0; 194 } 195 mCurrentProfilerData = mRootProfilerData; 196 mCurrentProfilerData->mNextForRoot = 0; 197 mCurrentProfilerData->mFirstChild = 0; 198 for(U32 i = 0; i < ProfilerData::HashTableSize; i++) 199 mCurrentProfilerData->mChildHash[i] = 0; 200 mCurrentProfilerData->mInvokeCount = 0; 201 mCurrentProfilerData->mTotalTime = 0; 202 mCurrentProfilerData->mSubTime = 0; 203 mCurrentProfilerData->mSubDepth = 0; 204 mCurrentProfilerData->mLastSeenProfiler = 0; 205} 206 207static Profiler aProfiler; // allocate the global profiler 208 209ProfilerRootData::ProfilerRootData(const char *name) 210{ 211 for(ProfilerRootData *walk = sRootList; walk; walk = walk->mNextRoot) 212 if(!String::compare(walk->mName, name)) 213 AssertFatal( false, avar( "Duplicate profile name: %s", name ) ); 214 215 mName = name; 216 mNameHash = _StringTable::hashString(name); 217 mNextRoot = sRootList; 218 sRootList = this; 219 mTotalTime = 0; 220 mTotalInvokeCount = 0; 221 mFirstProfilerData = NULL; 222 mEnabled = true; 223} 224 225void Profiler::validate() 226{ 227 for(ProfilerRootData *walk = ProfilerRootData::sRootList; walk; walk = walk->mNextRoot) 228 { 229 for(ProfilerData *dp = walk->mFirstProfilerData; dp; dp = dp->mNextForRoot) 230 { 231 if(dp->mRoot != walk) 232 Platform::debugBreak(); 233 // check if it's in the parent's list... 234 ProfilerData *wk; 235 for(wk = dp->mParent->mFirstChild; wk; wk = wk->mNextSibling) 236 if(wk == dp) 237 break; 238 if(!wk) 239 Platform::debugBreak(); 240 for(wk = dp->mParent->mChildHash[walk->mNameHash & (ProfilerData::HashTableSize - 1)] ; 241 wk; wk = wk->mNextHash) 242 if(wk == dp) 243 break; 244 if(!wk) 245 Platform::debugBreak(); 246 } 247 } 248} 249 250#ifdef TORQUE_ENABLE_PROFILE_PATH 251const char * Profiler::getProfilePath() 252{ 253#ifdef TORQUE_MULTITHREAD 254 // Ignore non-main-thread profiler activity. 255 if( !ThreadManager::isMainThread() ) 256 return "[non-main thread]"; 257#endif 258 259 return (mEnabled && mCurrentProfilerData) ? mCurrentProfilerData->mPath : "na"; 260} 261#endif 262 263#ifdef TORQUE_ENABLE_PROFILE_PATH 264const char * Profiler::constructProfilePath(ProfilerData * pd) 265{ 266 if (pd->mParent) 267 { 268 const bool saveEnable = gProfiler->mEnabled; 269 gProfiler->mEnabled = false; 270 271 const char * connector = " -> "; 272 U32 len = dStrlen(pd->mParent->mPath); 273 if (!len) 274 connector = ""; 275 len += dStrlen(connector); 276 len += dStrlen(pd->mRoot->mName); 277 278 U32 mark = FrameAllocator::getWaterMark(); 279 char * buf = (char*)FrameAllocator::alloc(len+1); 280 dStrcpy(buf,pd->mParent->mPath,len+1); 281 dStrcat(buf,connector,len+1); 282 dStrcat(buf,pd->mRoot->mName,len+1); 283 const char * ret = StringTable->insert(buf); 284 FrameAllocator::setWaterMark(mark); 285 286 gProfiler->mEnabled = saveEnable; 287 288 return ret; 289 } 290 return "root"; 291} 292#endif 293void Profiler::hashPush(ProfilerRootData *root) 294{ 295#ifdef TORQUE_MULTITHREAD 296 // Ignore non-main-thread profiler activity. 297 if( !ThreadManager::isMainThread() ) 298 return; 299#endif 300 301 mStackDepth++; 302 PROFILER_DEBUG_PUSH_NODE(root->mName); 303 AssertFatal(mStackDepth <= mMaxStackDepth, 304 "Stack overflow in profiler. You may have mismatched PROFILE_START and PROFILE_ENDs"); 305 if(!mEnabled) 306 return; 307 308 ProfilerData *nextProfiler = NULL; 309 if(!root->mEnabled || mCurrentProfilerData->mRoot == root) 310 { 311 mCurrentProfilerData->mSubDepth++; 312 return; 313 } 314 315 if(mCurrentProfilerData->mLastSeenProfiler && 316 mCurrentProfilerData->mLastSeenProfiler->mRoot == root) 317 nextProfiler = mCurrentProfilerData->mLastSeenProfiler; 318 319 if(!nextProfiler) 320 { 321 // first see if it's in the hash table... 322 U32 index = root->mNameHash & (ProfilerData::HashTableSize - 1); 323 nextProfiler = mCurrentProfilerData->mChildHash[index]; 324 while(nextProfiler) 325 { 326 if(nextProfiler->mRoot == root) 327 break; 328 nextProfiler = nextProfiler->mNextHash; 329 } 330 if(!nextProfiler) 331 { 332 nextProfiler = (ProfilerData *) malloc(sizeof(ProfilerData)); 333 for(U32 i = 0; i < ProfilerData::HashTableSize; i++) 334 nextProfiler->mChildHash[i] = 0; 335 336 nextProfiler->mRoot = root; 337 nextProfiler->mNextForRoot = root->mFirstProfilerData; 338 root->mFirstProfilerData = nextProfiler; 339 340 nextProfiler->mNextProfilerData = mProfileList; 341 mProfileList = nextProfiler; 342 343 nextProfiler->mNextHash = mCurrentProfilerData->mChildHash[index]; 344 mCurrentProfilerData->mChildHash[index] = nextProfiler; 345 346 nextProfiler->mParent = mCurrentProfilerData; 347 nextProfiler->mNextSibling = mCurrentProfilerData->mFirstChild; 348 mCurrentProfilerData->mFirstChild = nextProfiler; 349 nextProfiler->mFirstChild = NULL; 350 nextProfiler->mLastSeenProfiler = NULL; 351 nextProfiler->mHash = root->mNameHash; 352 nextProfiler->mInvokeCount = 0; 353 nextProfiler->mTotalTime = 0; 354 nextProfiler->mSubTime = 0; 355 nextProfiler->mSubDepth = 0; 356#ifdef TORQUE_ENABLE_PROFILE_PATH 357 nextProfiler->mPath = constructProfilePath(nextProfiler); 358#endif 359 } 360 } 361 root->mTotalInvokeCount++; 362 nextProfiler->mInvokeCount++; 363 startHighResolutionTimer(nextProfiler->mStartTime); 364 mCurrentProfilerData->mLastSeenProfiler = nextProfiler; 365 mCurrentProfilerData = nextProfiler; 366} 367 368void Profiler::enable(bool enabled) 369{ 370 mNextEnable = enabled; 371} 372 373void Profiler::dumpToConsole() 374{ 375 mDumpToConsole = true; 376 mDumpToFile = false; 377 mDumpFileName[0] = '\0'; 378} 379 380void Profiler::dumpToFile(const char* fileName) 381{ 382 AssertFatal(dStrlen(fileName) < DumpFileNameLength, "Error, dump filename too long"); 383 mDumpToFile = true; 384 mDumpToConsole = false; 385 dStrcpy(mDumpFileName, fileName, DumpFileNameLength); 386} 387 388void Profiler::hashPop(ProfilerRootData *expected) 389{ 390#ifdef TORQUE_MULTITHREAD 391 // Ignore non-main-thread profiler activity. 392 if( !ThreadManager::isMainThread() ) 393 return; 394#endif 395 396 mStackDepth--; 397 PROFILER_DEBUG_POP_NODE(); 398 AssertFatal(mStackDepth >= 0, "Stack underflow in profiler. You may have mismatched PROFILE_START and PROFILE_ENDs"); 399 if(mEnabled) 400 { 401 if(mCurrentProfilerData->mSubDepth) 402 { 403 mCurrentProfilerData->mSubDepth--; 404 return; 405 } 406 407 if(expected) 408 { 409 AssertISV(expected == mCurrentProfilerData->mRoot, "Profiler::hashPop - didn't get expected ProfilerRoot!"); 410 } 411 412 F64 fElapsed = endHighResolutionTimer(mCurrentProfilerData->mStartTime); 413 414 mCurrentProfilerData->mTotalTime += fElapsed; 415 mCurrentProfilerData->mParent->mSubTime += fElapsed; // mark it in the parent as well... 416 mCurrentProfilerData->mRoot->mTotalTime += fElapsed; 417 if(mCurrentProfilerData->mParent->mRoot) 418 mCurrentProfilerData->mParent->mRoot->mSubTime += fElapsed; // mark it in the parent as well... 419 420 mCurrentProfilerData = mCurrentProfilerData->mParent; 421 } 422 if(mStackDepth == 0) 423 { 424 // apply the next enable... 425 if(mDumpToConsole || mDumpToFile) 426 { 427 dump(); 428 startHighResolutionTimer(mCurrentProfilerData->mStartTime); 429 } 430 if(!mEnabled && mNextEnable) 431 startHighResolutionTimer(mCurrentProfilerData->mStartTime); 432 433#if defined(TORQUE_OS_WIN) 434 // The high performance counters under win32 are unreliable when running on multiple 435 // processors. When the profiler is enabled, we restrict Torque to a single processor. 436 if(mNextEnable != mEnabled) 437 { 438 439 if(mNextEnable) 440 { 441 Con::warnf("Warning: forcing the Torque profiler thread to run only on cpu 1."); 442 SetThreadAffinityMask(GetCurrentThread(), 1); 443 } 444 else 445 { 446 Con::warnf("Warning: the Torque profiler thread may now run on any cpu."); 447 DWORD_PTR procMask; 448 DWORD_PTR sysMask; 449 GetProcessAffinityMask( GetCurrentProcess(), &procMask, &sysMask); 450 SetThreadAffinityMask( GetCurrentThread(), procMask); 451 } 452 } 453#endif 454 455 mEnabled = mNextEnable; 456 } 457} 458 459static S32 QSORT_CALLBACK rootDataCompare(const void *s1, const void *s2) 460{ 461 const ProfilerRootData *r1 = *((ProfilerRootData **) s1); 462 const ProfilerRootData *r2 = *((ProfilerRootData **) s2); 463 if((r2->mTotalTime - r2->mSubTime) > (r1->mTotalTime - r1->mSubTime)) 464 return 1; 465 return -1; 466} 467 468static void profilerDataDumpRecurse(ProfilerData *data, char *buffer, U32 bufferLen, F64 totalTime) 469{ 470 // dump out this one: 471 Con::printf("%7.3f %7.3f %8d %s%s", 472 100 * data->mTotalTime / totalTime, 473 100 * (data->mTotalTime - data->mSubTime) / totalTime, 474 data->mInvokeCount, 475 buffer, 476 data->mRoot ? data->mRoot->mName : "ROOT" ); 477 data->mTotalTime = 0; 478 data->mSubTime = 0; 479 data->mInvokeCount = 0; 480 481 buffer[bufferLen] = ' '; 482 buffer[bufferLen+1] = ' '; 483 buffer[bufferLen+2] = 0; 484 // sort data's children... 485 ProfilerData *list = NULL; 486 while(data->mFirstChild) 487 { 488 ProfilerData *ins = data->mFirstChild; 489 data->mFirstChild = ins->mNextSibling; 490 ProfilerData **walk = &list; 491 while(*walk && (*walk)->mTotalTime > ins->mTotalTime) 492 walk = &(*walk)->mNextSibling; 493 ins->mNextSibling = *walk; 494 *walk = ins; 495 } 496 data->mFirstChild = list; 497 while(list) 498 { 499 if(list->mInvokeCount) 500 profilerDataDumpRecurse(list, buffer, bufferLen + 2, totalTime); 501 list = list->mNextSibling; 502 } 503 buffer[bufferLen] = 0; 504} 505 506static void profilerDataDumpRecurseFile(ProfilerData *data, char *buffer, U32 bufferLen, F64 totalTime, FileStream& fws) 507{ 508 char pbuffer[256]; 509 dSprintf(pbuffer, 255, "%7.3f %7.3f %8d %s%s\n", 510 100 * data->mTotalTime / totalTime, 511 100 * (data->mTotalTime - data->mSubTime) / totalTime, 512 data->mInvokeCount, 513 buffer, 514 data->mRoot ? data->mRoot->mName : "ROOT" ); 515 fws.write(dStrlen(pbuffer), pbuffer); 516 data->mTotalTime = 0; 517 data->mSubTime = 0; 518 data->mInvokeCount = 0; 519 520 buffer[bufferLen] = ' '; 521 buffer[bufferLen+1] = ' '; 522 buffer[bufferLen+2] = 0; 523 // sort data's children... 524 ProfilerData *list = NULL; 525 while(data->mFirstChild) 526 { 527 ProfilerData *ins = data->mFirstChild; 528 data->mFirstChild = ins->mNextSibling; 529 ProfilerData **walk = &list; 530 while(*walk && (*walk)->mTotalTime > ins->mTotalTime) 531 walk = &(*walk)->mNextSibling; 532 ins->mNextSibling = *walk; 533 *walk = ins; 534 } 535 data->mFirstChild = list; 536 while(list) 537 { 538 if(list->mInvokeCount) 539 profilerDataDumpRecurseFile(list, buffer, bufferLen + 2, totalTime, fws); 540 list = list->mNextSibling; 541 } 542 buffer[bufferLen] = 0; 543} 544 545void Profiler::dump() 546{ 547 bool enableSave = mEnabled; 548 mEnabled = false; 549 mStackDepth++; 550 // may have some profiled calls... gotta turn em off. 551 552 Vector<ProfilerRootData*> rootVector; 553 F64 totalTime = 0; 554 for(ProfilerRootData *walk = ProfilerRootData::sRootList; walk; walk = walk->mNextRoot) 555 { 556 totalTime += walk->mTotalTime - walk->mSubTime; 557 rootVector.push_back(walk); 558 } 559 dQsort((void *) &rootVector[0], rootVector.size(), sizeof(ProfilerRootData *), rootDataCompare); 560 561 562 if (mDumpToConsole == true) 563 { 564 Con::printf("Profiler Data Dump:"); 565 Con::printf("Ordered by non-sub total time -"); 566 Con::printf("%%NSTime %% Time Invoke # Name"); 567 for(U32 i = 0; i < rootVector.size(); i++) 568 { 569 Con::printf("%7.3f %7.3f %8d %s", 570 100 * (rootVector[i]->mTotalTime - rootVector[i]->mSubTime) / totalTime, 571 100 * rootVector[i]->mTotalTime / totalTime, 572 rootVector[i]->mTotalInvokeCount, 573 rootVector[i]->mName); 574 rootVector[i]->mTotalInvokeCount = 0; 575 rootVector[i]->mTotalTime = 0; 576 rootVector[i]->mSubTime = 0; 577 } 578 Con::printf(""); 579 Con::printf("Ordered by stack trace total time -"); 580 Con::printf("%% Time %% NSTime Invoke # Name"); 581 582 mCurrentProfilerData->mTotalTime = endHighResolutionTimer(mCurrentProfilerData->mStartTime); 583 584 char depthBuffer[MaxStackDepth * 2 + 1]; 585 depthBuffer[0] = 0; 586 profilerDataDumpRecurse(mCurrentProfilerData, depthBuffer, 0, totalTime); 587 mEnabled = enableSave; 588 mStackDepth--; 589 } 590 else if (mDumpToFile == true && mDumpFileName[0] != '\0') 591 { 592 FileStream fws; 593 bool success = fws.open(mDumpFileName, Torque::FS::File::Write); 594 AssertFatal(success, "Cannot write profile dump to specified file!"); 595 char buffer[1024]; 596 597 dStrcpy(buffer, "Profiler Data Dump:\n", 1024); 598 fws.write(dStrlen(buffer), buffer); 599 dStrcpy(buffer, "Ordered by non-sub total time -\n", 1024); 600 fws.write(dStrlen(buffer), buffer); 601 dStrcpy(buffer, "%%NSTime %% Time Invoke # Name\n", 1024); 602 fws.write(dStrlen(buffer), buffer); 603 604 for(U32 i = 0; i < rootVector.size(); i++) 605 { 606 dSprintf(buffer, 1023, "%7.3f %7.3f %8d %s\n", 607 100 * (rootVector[i]->mTotalTime - rootVector[i]->mSubTime) / totalTime, 608 100 * rootVector[i]->mTotalTime / totalTime, 609 rootVector[i]->mTotalInvokeCount, 610 rootVector[i]->mName); 611 fws.write(dStrlen(buffer), buffer); 612 613 rootVector[i]->mTotalInvokeCount = 0; 614 rootVector[i]->mTotalTime = 0; 615 rootVector[i]->mSubTime = 0; 616 } 617 dStrcpy(buffer, "\nOrdered by non-sub total time -\n", 1024); 618 fws.write(dStrlen(buffer), buffer); 619 dStrcpy(buffer, "%%NSTime %% Time Invoke # Name\n", 1024); 620 fws.write(dStrlen(buffer), buffer); 621 622 mCurrentProfilerData->mTotalTime = endHighResolutionTimer(mCurrentProfilerData->mStartTime); 623 624 char depthBuffer[MaxStackDepth * 2 + 1]; 625 depthBuffer[0] = 0; 626 profilerDataDumpRecurseFile(mCurrentProfilerData, depthBuffer, 0, totalTime, fws); 627 mEnabled = enableSave; 628 mStackDepth--; 629 630 fws.close(); 631 } 632 633 mDumpToConsole = false; 634 mDumpToFile = false; 635 mDumpFileName[0] = '\0'; 636} 637 638void Profiler::enableMarker(const char *marker, bool enable) 639{ 640 reset(); 641 U32 markerLen = dStrlen(marker); 642 if(markerLen == 0) 643 return; 644 bool sn = marker[markerLen - 1] == '*'; 645 for(ProfilerRootData *data = ProfilerRootData::sRootList; data; data = data->mNextRoot) 646 { 647 if(sn) 648 { 649 if(!dStrncmp(marker, data->mName, markerLen - 1)) 650 data->mEnabled = enable; 651 } 652 else 653 { 654 if(!String::compare(marker, data->mName)) 655 data->mEnabled = enable; 656 } 657 } 658} 659 660//============================================================================= 661// Console Functions. 662//============================================================================= 663// MARK: ---- Console Functions ---- 664 665//----------------------------------------------------------------------------- 666 667DefineEngineFunction( profilerMarkerEnable, void, ( const char* markerName, bool enable ), ( true ), 668 "@brief Enable or disable a specific profile.\n\n" 669 "@param enable Optional paramater to enable or disable the profile.\n" 670 "@param markerName Name of a specific marker to enable or disable.\n" 671 "@note Calling this function will first call profilerReset(), clearing all data from profiler. " 672 "All profile markers are enabled by default.\n\n" 673 "@ingroup Debugging") 674{ 675 if( gProfiler ) 676 gProfiler->enableMarker( markerName, enable ); 677} 678 679//----------------------------------------------------------------------------- 680 681DefineEngineFunction( profilerEnable, void, ( bool enable ),, 682 "@brief Enables or disables the profiler.\n\n" 683 "Data is only gathered while the profiler is enabled.\n\n" 684 "@note Profiler is not available in shipping builds.\n" 685 "T3D has predefined profiling areas surrounded by markers, " 686 "but you may need to define additional markers (in C++) around areas you wish to profile," 687 " by using the PROFILE_START( markerName ); and PROFILE_END(); macros.\n\n" 688 "@ingroup Debugging\n" ) 689{ 690 if(gProfiler) 691 gProfiler->enable(enable); 692} 693 694DefineEngineFunction(profilerDump, void, (),, 695 "@brief Dumps current profiling stats to the console window.\n\n" 696 "@note Markers disabled with profilerMarkerEnable() will be skipped over. " 697 "If the profiler is currently running, it will be disabled.\n" 698 "@ingroup Debugging") 699{ 700 if(gProfiler) 701 gProfiler->dumpToConsole(); 702} 703 704DefineEngineFunction( profilerDumpToFile, void, ( const char* fileName ),, 705 "@brief Dumps current profiling stats to a file.\n\n" 706 "@note If the profiler is currently running, it will be disabled.\n" 707 "@param fileName Name and path of file to save profiling stats to. Must use forward slashes (/). " 708 "Will attempt to create the file if it does not already exist.\n" 709 "@tsexample\n" 710 "profilerDumpToFile( \"C:/Torque/log1.txt\" );\n" 711 "@endtsexample\n\n" 712 "@ingroup Debugging" ) 713{ 714 if(gProfiler) 715 gProfiler->dumpToFile(fileName); 716} 717 718DefineEngineFunction( profilerReset, void, (),, 719 "@brief Resets the profiler, clearing it of all its data.\n\n" 720 "If the profiler is currently running, it will first be disabled. " 721 "All markers will retain their current enabled/disabled status.\n\n" 722 "@ingroup Debugging" ) 723{ 724 if(gProfiler) 725 gProfiler->reset(); 726} 727 728#endif 729