Browse Source

Reworked profiler output.

Lasse Öörni 13 years ago
parent
commit
ee5c66210e
4 changed files with 78 additions and 107 deletions
  1. 32 53
      Engine/Core/Profiler.cpp
  2. 43 48
      Engine/Core/Profiler.h
  3. 2 2
      Engine/Engine/DebugHud.cpp
  4. 1 4
      Engine/Engine/Engine.cpp

+ 32 - 53
Engine/Core/Profiler.cpp

@@ -40,7 +40,7 @@ Profiler::Profiler(Context* context) :
     Object(context),
     Object(context),
     current_(0),
     current_(0),
     root_(0),
     root_(0),
-    accumulatedFrames_(0),
+    intervalFrames_(0),
     totalFrames_(0)
     totalFrames_(0)
 {
 {
     root_ = new ProfilerBlock(0, "Root");
     root_ = new ProfilerBlock(0, "Root");
@@ -66,7 +66,7 @@ void Profiler::EndFrame()
     if (current_ != root_)
     if (current_ != root_)
     {
     {
         EndBlock();
         EndBlock();
-        ++accumulatedFrames_;
+        ++intervalFrames_;
         ++totalFrames_;
         ++totalFrames_;
         if (!totalFrames_)
         if (!totalFrames_)
             ++totalFrames_;
             ++totalFrames_;
@@ -75,39 +75,39 @@ void Profiler::EndFrame()
     }
     }
 }
 }
 
 
-void Profiler::ClearAccumulated()
+void Profiler::BeginInterval()
 {
 {
-    root_->ClearAccumulated();
-    accumulatedFrames_ = 0;
+    root_->BeginInterval();
+    intervalFrames_ = 0;
 }
 }
 
 
-String Profiler::GetData(bool showUnused, bool showAccumulated, bool showTotal, unsigned maxDepth) const
+String Profiler::GetData(bool showUnused, bool showTotal, unsigned maxDepth) const
 {
 {
     String output;
     String output;
     
     
     if (!showTotal)
     if (!showTotal)
-        output += String("Block                          Count   Average   Total\n \n");
+        output += String("Block                            Cnt     Avg      Max     Frame     Total\n\n");
     else
     else
     {
     {
-        output += String("Block                                       Frame average                    Accumulated total\n\n");
-        output += String("                                    Count     Average       Total      Count     Average       Total\n\n");
+        output += String("Block                                       Last frame                       Whole execution time\n\n");
+        output += String("                                 Cnt     Avg      Max      Total      Cnt      Avg       Max        Total\n\n");
     }
     }
     
     
     if (!maxDepth)
     if (!maxDepth)
         maxDepth = 1;
         maxDepth = 1;
     
     
-    GetData(root_, output, 0, maxDepth, showUnused, showAccumulated, showTotal);
+    GetData(root_, output, 0, maxDepth, showUnused, showTotal);
     
     
     return output;
     return output;
 }
 }
 
 
-void Profiler::GetData(ProfilerBlock* block, String& output, unsigned depth, unsigned maxDepth, bool showUnused, bool showAccumulated, bool showTotal) const
+void Profiler::GetData(ProfilerBlock* block, String& output, unsigned depth, unsigned maxDepth, bool showUnused, bool showTotal) const
 {
 {
     char line[LINE_MAX_LENGTH];
     char line[LINE_MAX_LENGTH];
     char indentedName[LINE_MAX_LENGTH];
     char indentedName[LINE_MAX_LENGTH];
     
     
     unsigned frames = Max(totalFrames_, 1);
     unsigned frames = Max(totalFrames_, 1);
-    unsigned accumulatedFrames = Max(accumulatedFrames_, 1);
+    unsigned intervalFrames = Max(intervalFrames_, 1);
     
     
     if (depth >= maxDepth)
     if (depth >= maxDepth)
         return;
         return;
@@ -115,64 +115,43 @@ void Profiler::GetData(ProfilerBlock* block, String& output, unsigned depth, uns
     // Do not print the root block as it does not collect any actual data
     // Do not print the root block as it does not collect any actual data
     if (block != root_)
     if (block != root_)
     {
     {
-        // Output data in milliseconds
-        float frameTime = block->GetFrameTime() / 1000.0f;
-        float accumulatedTime = block->GetAccumulatedTime() / 1000.0f;
-        float totalTime = block->GetTotalTime() / 1000.0f;
-        unsigned frameCount = block->GetFrameCount();
-        unsigned accumulatedCount = block->GetAccumulatedCount();
-        unsigned totalCount = block->GetTotalCount();
-        
-        float avgFrameTime = 0.0f;
-        float avgAccumulatedTime = 0.0f;
-        float avgTotalTime = 0.0f;
-        
-        if (frameCount)
-            avgFrameTime = frameTime / frameCount;
-        if (accumulatedCount)
-            avgAccumulatedTime = accumulatedTime / accumulatedCount;
-        if (totalCount)
-            avgTotalTime = totalTime / totalCount;
-        
-        if (showUnused || frameCount || (showAccumulated && accumulatedCount))
+        if (showUnused || block->intervalCount_ || (showTotal && block->totalCount_))
         {
         {
             memset(indentedName, ' ', NAME_MAX_LENGTH);
             memset(indentedName, ' ', NAME_MAX_LENGTH);
             indentedName[depth] = 0;
             indentedName[depth] = 0;
-            strcat(indentedName, block->GetName());
+            strcat(indentedName, block->name_);
             indentedName[strlen(indentedName)] = ' ';
             indentedName[strlen(indentedName)] = ' ';
             indentedName[NAME_MAX_LENGTH] = 0;
             indentedName[NAME_MAX_LENGTH] = 0;
             
             
             if (!showTotal)
             if (!showTotal)
             {
             {
-                if (!showAccumulated)
-                    sprintf(line, "%s %5u %8.3f %8.3f\n", indentedName, frameCount, avgFrameTime, frameTime);
-                else
-                    sprintf(line, "%s %5u %8.3f %8.3f\n", indentedName, 
-                        (unsigned)((float)accumulatedCount / accumulatedFrames + 0.5f),
-                        avgAccumulatedTime, accumulatedTime / accumulatedFrames);
+                float avg = (block->intervalCount_ ? block->intervalTime_ / block->intervalCount_ : 0.0f) / 1000.0f;
+                float max = block->intervalMaxTime_ / 1000.0f;
+                float frame = block->intervalTime_ / intervalFrames / 1000.0f;
+                float all = block->intervalTime_ / 1000.0f;
+        
+                sprintf(line, "%s %5u %8.3f %8.3f %8.3f %9.3f\n", indentedName, block->intervalCount_, avg, max, frame, all);
             }
             }
             else
             else
             {
             {
-                unsigned avgFrameCount = (unsigned)((float)totalCount / frames + 0.5f);
-                float avgFrameTime = avgTotalTime;
-                float avgFrameTotalTime = totalTime / frames;
-                if (!avgFrameCount)
-                {
-                    avgFrameTime = 0.0f;
-                    avgFrameTotalTime = 0.0f;
-                }
+                float avg = (block->frameCount_ ? block->frameTime_ / block->frameCount_ : 0.0f) / 1000.0f;
+                float max = block->frameMaxTime_ / 1000.0f;
+                float all = block->frameTime_ / 1000.0f;
+                
+                float totalAvg = (block->totalCount_ ? block->totalTime_ / block->totalCount_ : 0.0f) / 1000.0f;
+                float totalMax = block->totalMaxTime_ / 1000.0f;
+                float totalAll = block->totalTime_ / 1000.0f;
                 
                 
-                sprintf(line, "%s %10u %11.3f %11.3f %10u %11.3f %11.3f\n",
-                    indentedName, avgFrameCount, avgFrameTime, avgFrameTotalTime,
-                    totalCount, avgTotalTime, totalTime);
+                sprintf(line, "%s %5u %8.3f %8.3f %9.3f  %7u %9.3f %9.3f %11.3f\n", indentedName, block->frameCount_, avg, max,
+                    all, block->totalCount_, totalAvg, totalMax, totalAll);
             }
             }
+            
             output += String(line);
             output += String(line);
         }
         }
         
         
         ++depth;
         ++depth;
     }
     }
     
     
-    const PODVector<ProfilerBlock*>& children = block->GetChildren();
-    for (PODVector<ProfilerBlock*>::ConstIterator i = children.Begin(); i != children.End(); ++i)
-        GetData(*i, output, depth, maxDepth, showUnused, showAccumulated, showTotal);
+    for (PODVector<ProfilerBlock*>::ConstIterator i = block->children_.Begin(); i != block->children_.End(); ++i)
+        GetData(*i, output, depth, maxDepth, showUnused, showTotal);
 }
 }

+ 43 - 48
Engine/Core/Profiler.h

@@ -39,10 +39,13 @@ public:
         lastSearchName_(0),
         lastSearchName_(0),
         lastSearchBlock_(0),
         lastSearchBlock_(0),
         frameTime_(0),
         frameTime_(0),
+        frameMaxTime_(0),
         frameCount_(0),
         frameCount_(0),
-        accumulatedTime_(0),
-        accumulatedCount_(0),
+        intervalTime_(0),
+        intervalMaxTime_(0),
+        intervalCount_(0),
         totalTime_(0),
         totalTime_(0),
+        totalMaxTime_(0),
         totalCount_(0)
         totalCount_(0)
     {
     {
     }
     }
@@ -73,30 +76,37 @@ public:
         time_ += time;
         time_ += time;
     }
     }
     
     
-    /// End profiling frame and update accumulation period and total values.
+    /// End profiling frame and update interval and total values.
     void EndFrame()
     void EndFrame()
     {
     {
         frameTime_ = time_;
         frameTime_ = time_;
+        frameMaxTime_ = maxTime_;
         frameCount_ = count_;
         frameCount_ = count_;
-        accumulatedTime_ += time_;
-        accumulatedCount_ += count_;
+        intervalTime_ += time_;
+        if (maxTime_ > intervalMaxTime_)
+            intervalMaxTime_ = maxTime_;
+        intervalCount_ += count_;
         totalTime_ += time_;
         totalTime_ += time_;
+        if (maxTime_ > totalMaxTime_)
+            totalMaxTime_ = maxTime_;
         totalCount_ += count_;
         totalCount_ += count_;
         time_ = 0;
         time_ = 0;
+        maxTime_ = 0;
         count_ = 0;
         count_ = 0;
         
         
         for (PODVector<ProfilerBlock*>::Iterator i = children_.Begin(); i != children_.End(); ++i)
         for (PODVector<ProfilerBlock*>::Iterator i = children_.Begin(); i != children_.End(); ++i)
             (*i)->EndFrame();
             (*i)->EndFrame();
     }
     }
     
     
-    /// Clear accumulation period data.
-    void ClearAccumulated()
+    /// Begin new profiling interval.
+    void BeginInterval()
     {
     {
-        accumulatedTime_ = 0;
-        accumulatedCount_ = 0;
+        intervalTime_ = 0;
+        intervalMaxTime_ = 0;
+        intervalCount_ = 0;
         
         
         for (PODVector<ProfilerBlock*>::Iterator i = children_.Begin(); i != children_.End(); ++i)
         for (PODVector<ProfilerBlock*>::Iterator i = children_.Begin(); i != children_.End(); ++i)
-            (*i)->ClearAccumulated();
+            (*i)->BeginInterval();
     }
     }
     
     
     /// Return child block with the specified name.
     /// Return child block with the specified name.
@@ -123,36 +133,13 @@ public:
         return newBlock;
         return newBlock;
     }
     }
     
     
-    /// Return name of block.
-    const char* GetName() const { return name_; }
-    
-    /// Return maximum time of a single call.
-    long long GetMaxTime() const { return maxTime_; }
-    /// Return accumulated time during last frame.
-    long long GetFrameTime() const { return frameTime_; }
-    /// Return number of calls during last frame.
-    unsigned GetFrameCount() const { return frameCount_; }
-    /// Return accumulated time during the current accumulation period.
-    long long GetAccumulatedTime() const { return accumulatedTime_; }
-    /// Return number of calls during the current accumulation period.
-    unsigned GetAccumulatedCount() const { return accumulatedCount_; }
-    /// Return total accumulated time.
-    long long GetTotalTime() const { return totalTime_; }
-    /// Return total number of calls.
-    unsigned GetTotalCount() const { return totalCount_; }
-    /// Return parent block.
-    ProfilerBlock* GetParent() const { return parent_; }
-    /// Return child blocks.
-    const PODVector<ProfilerBlock*>& GetChildren() const { return children_; }
-    
-private:
     /// Block name.
     /// Block name.
     const char* name_;
     const char* name_;
     /// High-resolution timer for measuring the block duration.
     /// High-resolution timer for measuring the block duration.
     HiresTimer timer_;
     HiresTimer timer_;
     /// Time on current frame.
     /// Time on current frame.
     long long time_;
     long long time_;
-    /// Maximum time on a block.
+    /// Maximum time on current frame.
     long long maxTime_;
     long long maxTime_;
     /// Calls on current frame.
     /// Calls on current frame.
     unsigned count_;
     unsigned count_;
@@ -166,15 +153,21 @@ private:
     PODVector<ProfilerBlock*> children_;
     PODVector<ProfilerBlock*> children_;
     /// Time on the previous frame.
     /// Time on the previous frame.
     long long frameTime_;
     long long frameTime_;
+    /// Maximum time on the previous frame.
+    long long frameMaxTime_;
     /// Calls on the previous frame.
     /// Calls on the previous frame.
     unsigned frameCount_;
     unsigned frameCount_;
-    /// Time on the accumulation period.
-    long long accumulatedTime_;
-    /// Calls on the accumulation period.
-    unsigned accumulatedCount_;
-    /// Total time.
+    /// Time during current profiler interval.
+    long long intervalTime_;
+    /// Maximum time during current profiler interval.
+    long long intervalMaxTime_;
+    /// Calls during current profiler interval.
+    unsigned intervalCount_;
+    /// Total accumulated time.
     long long totalTime_;
     long long totalTime_;
-    /// Total calls.
+    /// All-time maximum time.
+    long long totalMaxTime_;
+    /// Total accumulated calls.
     unsigned totalCount_;
     unsigned totalCount_;
 };
 };
 
 
@@ -202,7 +195,7 @@ public:
         if (current_ != root_)
         if (current_ != root_)
         {
         {
             current_->End();
             current_->End();
-            current_ = current_->GetParent();
+            current_ = current_->parent_;
         }
         }
     }
     }
     
     
@@ -210,24 +203,26 @@ public:
     void BeginFrame();
     void BeginFrame();
     /// End the profiling frame. Called by HandleEndFrame().
     /// End the profiling frame. Called by HandleEndFrame().
     void EndFrame();
     void EndFrame();
-    /// Begin a new accumulation period.
-    void ClearAccumulated();
+    /// Begin a new interval.
+    void BeginInterval();
     
     
     /// Return profiling data as text output.
     /// Return profiling data as text output.
-    String GetData(bool showUnused = false, bool showAccumulated = false, bool showTotal = false, unsigned maxDepth = M_MAX_UNSIGNED) const;
+    String GetData(bool showUnused = false, bool showTotal = false, unsigned maxDepth = M_MAX_UNSIGNED) const;
     /// Return the current profiling block.
     /// Return the current profiling block.
     const ProfilerBlock* GetCurrentBlock() { return current_; }
     const ProfilerBlock* GetCurrentBlock() { return current_; }
+    /// Return the root profiling block.
+    const ProfilerBlock* GetRootBlock() { return root_; }
     
     
 private:
 private:
     /// Return profiling data as text output for a specified profiling block.
     /// Return profiling data as text output for a specified profiling block.
-    void GetData(ProfilerBlock* block, String& output, unsigned depth, unsigned maxDepth, bool showUnused, bool showAccumulated, bool showTotal) const;
-
+    void GetData(ProfilerBlock* block, String& output, unsigned depth, unsigned maxDepth, bool showUnused, bool showTotal) const;
+    
     /// Current profiling block.
     /// Current profiling block.
     ProfilerBlock* current_;
     ProfilerBlock* current_;
     /// Root profiling block.
     /// Root profiling block.
     ProfilerBlock* root_;
     ProfilerBlock* root_;
-    /// Frames in the current accumulation period.
-    unsigned accumulatedFrames_;
+    /// Frames in the current interval.
+    unsigned intervalFrames_;
     /// Total frames.
     /// Total frames.
     unsigned totalFrames_;
     unsigned totalFrames_;
 };
 };

+ 2 - 2
Engine/Engine/DebugHud.cpp

@@ -187,11 +187,11 @@ void DebugHud::Update()
 
 
             if (profilerText_->IsVisible())
             if (profilerText_->IsVisible())
             {
             {
-                String profilerOutput = profiler->GetData(false, true, false, profilerMaxDepth_);
+                String profilerOutput = profiler->GetData(false, false, profilerMaxDepth_);
                 profilerText_->SetText(profilerOutput);
                 profilerText_->SetText(profilerOutput);
             }
             }
 
 
-            profiler->ClearAccumulated();
+            profiler->BeginInterval();
         }
         }
     }
     }
 }
 }

+ 1 - 4
Engine/Engine/Engine.cpp

@@ -346,10 +346,7 @@ void Engine::DumpProfilingData()
 {
 {
     Profiler* profiler = GetSubsystem<Profiler>();
     Profiler* profiler = GetSubsystem<Profiler>();
     if (profiler)
     if (profiler)
-    {
-        profiler->EndFrame();
-        LOGRAW(profiler->GetData(true, false, true) + "\n");
-    }
+        LOGRAW(profiler->GetData(true, true) + "\n");
 }
 }
 
 
 void Engine::DumpResources()
 void Engine::DumpResources()