From: David Gow Date: Tue, 14 Oct 2014 06:48:02 +0000 (+0800) Subject: Added a profiler, which outputs time taken and calls to various functions. X-Git-Url: https://git.ucc.asn.au/?a=commitdiff_plain;h=a8297c3461718f2d9afc7a2f8ca620d320ac5f97;p=ipdf%2Fcode.git Added a profiler, which outputs time taken and calls to various functions. Disable by defining PROFILER_SILENT You can add a zone with PROFILE_SCOPE(name); (which will profile until the scope is exited) or with g_profiler.BeginZone(name); and g_profiler.EndZone(); --- diff --git a/src/Makefile b/src/Makefile index b7489c8..fee307d 100644 --- a/src/Makefile +++ b/src/Makefile @@ -10,7 +10,7 @@ else endif MAIN = main.o -OBJ = log.o real.o bezier.o objectrenderer.o view.o screen.o graphicsbuffer.o framebuffer.o shaderprogram.o stb_truetype.o gl_core44.o path.o document.o debugscript.o paranoidnumber.o +OBJ = log.o profiler.o real.o bezier.o objectrenderer.o view.o screen.o graphicsbuffer.o framebuffer.o shaderprogram.o stb_truetype.o gl_core44.o path.o document.o debugscript.o paranoidnumber.o QT_INCLUDE := -I/usr/share/qt4/mkspecs/linux-g++-64 -I. -I/usr/include/qt4/QtCore -I/usr/include/qt4/QtGui -I/usr/include/qt4 -I. -Itests -I. QT_DEF := -DQT_NO_DEBUG -DQT_GUI_LIB -DQT_CORE_LIB diff --git a/src/document.cpp b/src/document.cpp index b10ebf5..aff9a23 100644 --- a/src/document.cpp +++ b/src/document.cpp @@ -1,5 +1,6 @@ #include "document.h" #include "bezier.h" +#include "profiler.h" #include #include @@ -101,6 +102,7 @@ void Document::GenBaseQuadtree() int Document::ClipObjectToQuadChild(int object_id, QuadTreeNodeChildren type) { + PROFILE_SCOPE("Document::ClipObjectToQuadChild"); switch (m_objects.types[object_id]) { case RECT_FILLED: @@ -168,6 +170,7 @@ int Document::ClipObjectToQuadChild(int object_id, QuadTreeNodeChildren type) } QuadTreeIndex Document::GenQuadChild(QuadTreeIndex parent, QuadTreeNodeChildren type) { + PROFILE_SCOPE("Document::GenQuadChild()"); QuadTreeIndex new_index = m_quadtree.nodes.size(); Debug("-------------- Generating Quadtree Node %d (parent %d, type %d) ----------------------", new_index, parent, type); m_quadtree.nodes.push_back(QuadTreeNode{QUADTREE_EMPTY, QUADTREE_EMPTY, QUADTREE_EMPTY, QUADTREE_EMPTY, parent, type, 0, 0, -1}); @@ -208,6 +211,7 @@ QuadTreeIndex Document::GenQuadChild(QuadTreeIndex parent, QuadTreeNodeChildren void Document::OverlayQuadChildren(QuadTreeIndex orig_parent, QuadTreeIndex parent, QuadTreeNodeChildren type) { + PROFILE_SCOPE("Document::OverlayQuadChildren()"); QuadTreeIndex new_index = m_quadtree.nodes.size(); Debug("-------------- Generating Quadtree Node %d (orig %d parent %d, type %d) ----------------------", new_index, orig_parent, parent, type); m_quadtree.nodes.push_back(QuadTreeNode{QUADTREE_EMPTY, QUADTREE_EMPTY, QUADTREE_EMPTY, QUADTREE_EMPTY, orig_parent, type, 0, 0, -1}); @@ -413,6 +417,7 @@ unsigned Document::AddBezier(const Bezier & bezier) unsigned Document::Add(ObjectType type, const Rect & bounds, unsigned data_index, QuadTreeIndex qti) { + PROFILE_SCOPE("Document::Add"); m_objects.types.push_back(type); m_objects.bounds.push_back(bounds); m_objects.data_indices.push_back(data_index); diff --git a/src/main.h b/src/main.h index 654aa09..75c4b18 100644 --- a/src/main.h +++ b/src/main.h @@ -4,6 +4,7 @@ #include "view.h" #include "screen.h" #include "debugscript.h" +#include "profiler.h" #include @@ -122,7 +123,9 @@ void MainLoop(Document & doc, Screen & scr, View & view, int max_frames = -1) real_clock_prev = real_clock_now; #endif ++frames; + g_profiler.BeginZone("scr.Clear()"); scr.Clear(); + g_profiler.EndZone(); //view.ForceBoundsDirty(); //view.ForceBufferDirty(); //view.ForceRenderDirty(); @@ -133,7 +136,9 @@ void MainLoop(Document & doc, Screen & scr, View & view, int max_frames = -1) return; } + g_profiler.BeginZone("view.Render"); view.Render(scr.ViewportWidth(), scr.ViewportHeight()); + g_profiler.EndZone(); double cpu_frame = scr.GetLastFrameTimeCPU(); double gpu_frame = scr.GetLastFrameTimeGPU(); @@ -206,6 +211,9 @@ void MainLoop(Document & doc, Screen & scr, View & view, int max_frames = -1) } #endif // 0 + g_profiler.BeginZone("scr.Present()"); scr.Present(); + g_profiler.EndZone(); + g_profiler.EndFrame(); } } diff --git a/src/profiler.cpp b/src/profiler.cpp new file mode 100644 index 0000000..4348603 --- /dev/null +++ b/src/profiler.cpp @@ -0,0 +1,40 @@ +#include "profiler.h" +#include "log.h" + +#include "SDL.h" + +using namespace IPDF; + +Profiler IPDF::g_profiler; + +void Profiler::BeginZone(std::string name) +{ + if (!m_zones.count(name)) + m_zones[name] = ProfileZone{0,0,0,0,0,0}; + m_zones[name].tics_begin = SDL_GetPerformanceCounter(); + m_zone_stack.push(name); +} + +void Profiler::EndZone() +{ + std::string name = m_zone_stack.top(); + m_zone_stack.pop(); + m_zones[name].tics_end = SDL_GetPerformanceCounter(); + m_zones[name].tics_frame += m_zones[name].tics_end - m_zones[name].tics_begin; + m_zones[name].tics_total += m_zones[name].tics_end - m_zones[name].tics_begin; + m_zones[name].calls_frame++; + m_zones[name].calls_total++; +} + +void Profiler::EndFrame() +{ + // Zero all of the frame counts + for (auto& it : m_zones) + { +#ifndef PROFILER_SILENT + Debug("Perf: Zone \"%s\" frame: %d ms (%d calls), total: %d ms (%d calls)", it.first.c_str(), it.second.tics_frame * 1000 / SDL_GetPerformanceFrequency(), it.second.calls_frame, it.second.tics_total * 1000 / SDL_GetPerformanceFrequency(), it.second.calls_total); +#endif + it.second.tics_frame = 0; + it.second.calls_frame = 0; + } +} diff --git a/src/profiler.h b/src/profiler.h new file mode 100644 index 0000000..a20b8d8 --- /dev/null +++ b/src/profiler.h @@ -0,0 +1,45 @@ +#ifndef _PROFILER_H +#define _PROFILER_H + +#include +#include +#include + +#define PROFILE_SCOPE(name) IPDF::ProfilerScope _localProfZone(name) + +namespace IPDF +{ + class Profiler + { + public: + Profiler() {} + + void BeginZone(std::string name); + void EndZone(); + + void EndFrame(); + private: + struct ProfileZone + { + uint64_t tics_begin; + uint64_t tics_end; + uint64_t tics_frame; + uint64_t tics_total; + uint64_t calls_frame; + uint64_t calls_total; + }; + + std::map m_zones; + std::stack m_zone_stack; + }; + + extern Profiler g_profiler; + struct ProfilerScope + { + ProfilerScope(std::string name) { g_profiler.BeginZone(name); } + ~ProfilerScope() { g_profiler.EndZone(); } + }; + +} + +#endif diff --git a/src/view.cpp b/src/view.cpp index 3de7fb4..b489e08 100644 --- a/src/view.cpp +++ b/src/view.cpp @@ -1,6 +1,7 @@ #include "view.h" #include "bufferbuilder.h" #include "screen.h" +#include "profiler.h" #include "gl_core44.h" #ifndef CONTROLPANEL_DISABLED @@ -87,6 +88,7 @@ View::~View() */ void View::Translate(Real x, Real y) { + PROFILE_SCOPE("View::Translate"); if (!m_use_gpu_transform) m_buffer_dirty = true; m_bounds_dirty = true; @@ -134,7 +136,7 @@ void View::SetBounds(const Rect & bounds) */ void View::ScaleAroundPoint(Real x, Real y, Real scale_amount) { - + PROFILE_SCOPE("View::ScaleAroundPoint"); // (x0, y0, w, h) -> (x*w - (x*w - x0)*s, y*h - (y*h - y0)*s, w*s, h*s) // x and y are coordinates in the window // Convert to local coords. @@ -193,6 +195,7 @@ Rect View::TransformToViewCoords(const Rect& inp) const */ void View::Render(int width, int height) { + PROFILE_SCOPE("View::Render()"); if (!m_screen.Valid()) return; glPushDebugGroup(GL_DEBUG_SOURCE_APPLICATION,42,-1, "Beginning View::Render()"); // View dimensions have changed (ie: Window was resized) @@ -228,6 +231,7 @@ void View::Render(int width, int height) // quadtree node). if (m_bounds_dirty || !m_lazy_rendering) { + g_profiler.BeginZone("View::Render -- Quadtree view bounds management"); // If we're too far zoomed out, become the parent of the current node. if ( m_bounds.w > 1.0 || m_bounds.h > 1.0) { @@ -327,6 +331,7 @@ void View::Render(int width, int height) m_bounds = TransformToQuadChild(m_bounds, QTC_BOTTOM_RIGHT); m_current_quadtree_node = m_document.GetQuadTree().nodes[m_current_quadtree_node].bottom_right; } + g_profiler.EndZone(); } m_screen.DebugFontPrintF("Current View QuadTree"); @@ -453,6 +458,7 @@ void View::RenderQuadtreeNode(int width, int height, QuadTreeIndex node, int rem void View::RenderRange(int width, int height, unsigned first_obj, unsigned last_obj) { + PROFILE_SCOPE("View::RenderRange"); glPushDebugGroup(GL_DEBUG_SOURCE_APPLICATION, 43, -1, "View::RenderRange()"); if (m_render_dirty) // document has changed PrepareRender(); @@ -521,6 +527,7 @@ void View::RenderRange(int width, int height, unsigned first_obj, unsigned last_ void View::UpdateObjBoundsVBO(unsigned first_obj, unsigned last_obj) { + PROFILE_SCOPE("View::UpdateObjBoundsVBO"); if (m_query_gpu_bounds_on_next_frame != NULL) { fprintf(m_query_gpu_bounds_on_next_frame,"# View: %s\t%s\t%s\t%s", Str(m_bounds.x).c_str(), Str(m_bounds.y).c_str(), Str(m_bounds.w).c_str(), Str(m_bounds.h).c_str()); @@ -633,6 +640,7 @@ void View::UpdateObjBoundsVBO(unsigned first_obj, unsigned last_obj) */ void View::PrepareRender() { + PROFILE_SCOPE("View::PrepareRender()"); Debug("Recreate buffers with %u objects", m_document.ObjectCount()); // Prepare bounds vbo if (UsingGPURendering())