profiler.cpp

Engine/source/platform/profiler.cpp

More...

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*)&current);
 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