Improved GPU profiling code.

Now only allows a certain number of active queries,
this fixes results with applications that have many draw calls.

diff --git a/common/trace_profiler.cpp b/common/trace_profiler.cpp
index fdc0fd4a2f748c170c464bbd7af12e6852d4f68b..fd684ede7bf16d623b7b54b9f80e67477aaf8bc8 100644 (file)
--- a/common/trace_profiler.cpp
+++ b/common/trace_profiler.cpp
@@ -36,26 +36,41 @@ Profiler::~Profiler()
 {
 }
 
-void Profiler::addCall(const Call& call)
+void Profiler::addCall(unsigned no, const char *name, uint64_t gpu_start, uint64_t gpu_duration)
 {
     if (baseTime == 0)
-        baseTime = call.gpu.start;
+        baseTime = gpu_start;
 
     std::cout << "call "
-              << call.no << " "
-              << (call.gpu.start - baseTime) << " "
-              << call.gpu.duration << " "
-              << call.name << std::endl;
+              << no << " "
+              << (gpu_start - baseTime) << " "
+              << gpu_duration << " "
+              << name << std::endl;
 }
 
-void Profiler::addFrame(const Frame& frame)
+void Profiler::addFrameStart(unsigned no, uint64_t timestamp)
 {
     if (baseTime == 0)
-        baseTime = frame.gpu.start;
+        baseTime = timestamp;
 
-    std::cout << "frame "
-              << frame.no << " "
-              << (frame.gpu.start - baseTime) << " "
-              << frame.gpu.duration << std::endl;
+    lastFrame.no = no;
+    lastFrame.start = timestamp - baseTime;
+
+    std::cout << "frame begin "
+              << lastFrame.no << " "
+              << lastFrame.start << std::endl;
+}
+
+void Profiler::addFrameEnd(uint64_t timestamp)
+{
+    if (baseTime == 0)
+        baseTime = timestamp;
+
+    lastFrame.end = timestamp - baseTime;
+
+    std::cout << "frame end "
+              << lastFrame.no << " "
+              << lastFrame.end << " "
+              << (lastFrame.end - lastFrame.start) << std::endl;
 }
 }

diff --git a/common/trace_profiler.hpp b/common/trace_profiler.hpp
index 19a874f9b4fb4199c538d11aff68a161f84f12f3..191ac72ffe34c38e0da3851e1d6d7ad51dd62976 100644 (file)
--- a/common/trace_profiler.hpp
+++ b/common/trace_profiler.hpp
@@ -33,66 +33,23 @@ namespace trace
 {
 class Profiler
 {
-public:
-    struct GpuTime
-    {
-        GpuTime()
-            : start(0), duration(0)
-        {
-        }
-
-        GpuTime(uint64_t start_, uint64_t duration_)
-            : start(start_), duration(duration_)
-        {
-        }
-
-        uint64_t start;
-        uint64_t duration;
-    };
-
-    struct Call
-    {
-        Call()
-            : no(0)
-        {
-        }
-
-        Call(unsigned no_, const char* name_, uint64_t gpu_start, uint64_t gpu_duration)
-            : no(no_), name(name_), gpu(gpu_start, gpu_duration)
-        {
-        }
-
-        unsigned no;
-        std::string name;
-
-        GpuTime gpu;
-    };
-
-    struct Frame
-    {
-        Frame()
-            : no(0)
-        {
-        }
-
-        Frame(unsigned no_, uint64_t gpu_start, uint64_t gpu_duration)
-            : no(no_), gpu(gpu_start, gpu_duration)
-        {
-        }
-
-        unsigned no;
-        GpuTime gpu;
-    };
-
 public:
     Profiler();
     ~Profiler();
 
-    void addCall(const Call& call);
-    void addFrame(const Frame& frame);
+    void addCall(unsigned no, const char* name, uint64_t gpu_start, uint64_t gpu_duration);
+
+    void addFrameStart(unsigned no, uint64_t timestamp);
+    void addFrameEnd(uint64_t timestamp);
 
 private:
     uint64_t baseTime;
+
+    struct {
+        unsigned no;
+        uint64_t start;
+        uint64_t end;
+    } lastFrame;
 };
 }
 

diff --git a/retrace/glretrace.hpp b/retrace/glretrace.hpp
index 820b4e10f94ab3c0f9524e6ec4045645fe61778f..2ab85e03fda624da0d1e51b7cee6a10d2fba5f34 100644 (file)
--- a/retrace/glretrace.hpp
+++ b/retrace/glretrace.hpp
@@ -70,7 +70,6 @@ void frame_complete(trace::Call &call);
 
 void updateDrawable(int width, int height);
 
-void completeQueries();
 void beginProfileGPU(trace::Call &call);
 void endProfileGPU(trace::Call &call);
 

diff --git a/retrace/glretrace_main.cpp b/retrace/glretrace_main.cpp
index 6dd44eba76060e1ef0513695f6374dae2a370420..a865b74433faf5ca52daeb5ebdb398b36a1ecaa2 100644 (file)
--- a/retrace/glretrace_main.cpp
+++ b/retrace/glretrace_main.cpp
@@ -85,105 +85,106 @@ checkGlError(trace::Call &call) {
 
 struct CallQuery
 {
-   GLuint ids[2];
-   unsigned call;
-   const trace::FunctionSig *sig;
+    GLuint ids[2];
+    unsigned call;
+    const trace::FunctionSig *sig;
 };
 
-static std::vector<CallQuery> callQueries;
-static GLuint frameQueries[2] = { 0, 0 };
+static const int maxActiveCallQueries = 256;
+static std::list<CallQuery> callQueries;
+static bool firstFrame = true;
 
-void frame_start() {
-   if (retrace::profileGPU) {
-      glGenQueries(2, frameQueries);
+static GLuint64
+getTimestamp() {
+    GLuint query;
+    GLuint64 timestamp;
 
-      /* Query frame start time */
-      glQueryCounter(frameQueries[0], GL_TIMESTAMP);
-   }
-}
-
-void frame_complete(trace::Call &call) {
-    if (retrace::profileGPU) {
-        /* Query frame end time */
-       glQueryCounter(frameQueries[1], GL_TIMESTAMP);
+    glGenQueries(1, &query);
 
-       completeQueries();
-    }
+    glQueryCounter(query, GL_TIMESTAMP);
+    glGetQueryObjectui64vEXT(query, GL_QUERY_RESULT, &timestamp);
 
-    retrace::frameComplete(call);
+    glDeleteQueries(1, &query);
 
-    /* Indicate start of next frame */
-    frame_start();
+    return timestamp;
+}
 
-    if (!currentDrawable) {
-        return;
-    }
+static void
+completeCallQuery(CallQuery& query) {
+    /* Get call start and duration */
+    GLuint64 timestamp, duration;
+    glGetQueryObjectui64vEXT(query.ids[0], GL_QUERY_RESULT, &timestamp);
+    glGetQueryObjectui64vEXT(query.ids[1], GL_QUERY_RESULT, &duration);
+    glDeleteQueries(2, query.ids);
 
-    if (retrace::debug && !currentDrawable->visible) {
-        retrace::warning(call) << "could not infer drawable size (glViewport never called)\n";
-    }
+    /* Add call to profile */
+    retrace::profiler.addCall(query.call, query.sig->name, timestamp, duration);
 }
 
 void
-completeQueries()
-{
-   if (callQueries.size() == 0)
-      return;
-
-   GLint available;
-   GLuint64 frameBegin, frameEnd;
+beginProfileGPU(trace::Call &call) {
+    if (firstFrame) {
+        frame_start();
+    }
 
-   /* Wait for frame to finish */
-   do {
-      glGetQueryObjectiv(frameQueries[1], GL_QUERY_RESULT_AVAILABLE, &available);
-   } while(!available);
+    /* Ensure we don't have TOO many queries waiting for results */
+    if (callQueries.size() >= maxActiveCallQueries) {
+        completeCallQuery(callQueries.front());
+        callQueries.pop_front();
+    }
 
-   /* Get frame start and end */
-   glGetQueryObjectui64vEXT(frameQueries[0], GL_QUERY_RESULT, &frameBegin);
-   glGetQueryObjectui64vEXT(frameQueries[1], GL_QUERY_RESULT, &frameEnd);
-   glDeleteQueries(2, frameQueries);
+    /* Create call query */
+    CallQuery query;
+    query.call = call.no;
+    query.sig = call.sig;
 
-   /* Add frame to profile */
-   retrace::profiler.addFrame(trace::Profiler::Frame(retrace::frameNo, frameBegin, frameEnd - frameBegin));
+    glGenQueries(2, query.ids);
+    glQueryCounter(query.ids[0], GL_TIMESTAMP);
+    glBeginQuery(GL_TIME_ELAPSED, query.ids[1]);
 
-   /* Loop through all active call queries */
-   for (std::vector<CallQuery>::iterator itr = callQueries.begin(); itr != callQueries.end(); ++itr) {
-      CallQuery& query = *itr;
-      GLuint64 timestamp, duration;
+    callQueries.push_back(query);
+}
 
-      /* Get queue start and duration */
-      glGetQueryObjectui64vEXT(query.ids[0], GL_QUERY_RESULT, &timestamp);
-      glGetQueryObjectui64vEXT(query.ids[1], GL_QUERY_RESULT, &duration);
-      glDeleteQueries(2, query.ids);
+void
+endProfileGPU(trace::Call &call) {
+    glEndQuery(GL_TIME_ELAPSED);
+}
 
-      /* Add call to profile */
-      retrace::profiler.addCall(trace::Profiler::Call(query.call, query.sig->name, timestamp, duration));
-   }
+void
+frame_start() {
+    firstFrame = false;
 
-   callQueries.clear();
+    if (retrace::profileGPU) {
+        retrace::profiler.addFrameStart(retrace::frameNo, getTimestamp());
+    }
 }
 
 void
-beginProfileGPU(trace::Call &call) {
-   if (frameQueries[0] == 0) {
-      frame_start();
-   }
+frame_complete(trace::Call &call) {
+    if (retrace::profileGPU) {
+        /* Complete any remaining queries */
+        for (std::list<CallQuery>::iterator itr = callQueries.begin(); itr != callQueries.end(); ++itr) {
+            completeCallQuery(*itr);
+        }
 
-   CallQuery query;
-   query.call = call.no;
-   query.sig = call.sig;
+        callQueries.clear();
 
-   /* Create start and duration queries */
-   glGenQueries(2, query.ids);
-   glQueryCounter(query.ids[0], GL_TIMESTAMP);
-   glBeginQuery(GL_TIME_ELAPSED, query.ids[1]);
+        /* Indicate end of current frame */
+        retrace::profiler.addFrameEnd(getTimestamp());
+    }
 
-   callQueries.push_back(query);
-}
+    retrace::frameComplete(call);
 
-void
-endProfileGPU(trace::Call &call) {
-   glEndQuery(GL_TIME_ELAPSED);
+    /* Indicate start of next frame */
+    frame_start();
+
+    if (!currentDrawable) {
+        return;
+    }
+
+    if (retrace::debug && !currentDrawable->visible) {
+        retrace::warning(call) << "could not infer drawable size (glViewport never called)\n";
+    }
 }
 
 } /* namespace glretrace */

diff --git a/retrace/retrace_main.cpp b/retrace/retrace_main.cpp
index 164a596d4861830b775f73593e3f62b9b883a494..2c14b875a788814da4e54e51b13eb725c1cf82ea 100644 (file)
--- a/retrace/retrace_main.cpp
+++ b/retrace/retrace_main.cpp
@@ -171,7 +171,7 @@ mainLoop() {
     long long endTime = os::getTime();
     float timeInterval = (endTime - startTime) * (1.0 / os::timeFrequency);
 
-    if ((retrace::verbosity >= -1) || (retrace::profiling)) {
+    if ((retrace::verbosity >= -1) || (retrace::profiling) || (retrace::profileGPU)) {
         std::cout << 
             "Rendered " << frameNo << " frames"
             " in " <<  timeInterval << " secs,"
@@ -197,6 +197,7 @@ usage(const char *argv0) {
         "\n"
         "  -b           benchmark mode (no error checking or warning messages)\n"
         "  -p           profiling mode (run whole trace, dump profiling info)\n"
+        "  -pgpu        gpu profiling mode (run whole trace, dump gpu profiling info)\n"
         "  -c PREFIX    compare against snapshots\n"
         "  -C CALLSET   calls to compare (default is every frame)\n"
         "  -core        use core profile\n"
@@ -237,6 +238,10 @@ int main(int argc, char **argv)
             retrace::verbosity = -1;
         } else if (!strcmp(arg, "-pgpu")) {
             retrace::profileGPU = true;
+
+            retrace::debug = false;
+            retrace::profiling = false;
+            retrace::verbosity = -1;
         } else if (!strcmp(arg, "-c")) {
             comparePrefix = argv[++i];
             if (compareFrequency.empty()) {