Add simple CPU profiling support to glretrace.

This will note the time that each traced call required, and will dump
this information during the replay, giving a basic idea of where CPU
time was spent in the GL.

Signed-off-by: José Fonseca <jose.r.fonseca@gmail.com>

diff --git a/common/trace_dump.cpp b/common/trace_dump.cpp
index fd1d16a98c8d86cb50fc8b575329adf164974f48..c55bbb1ca324e776ad67b5cef5f72cb64376ed1e 100644 (file)
--- a/common/trace_dump.cpp
+++ b/common/trace_dump.cpp
@@ -200,6 +200,10 @@ public:
 
     void visit(Call *call) {
         CallFlags callFlags = call->flags;
+        
+        if (!(dumpFlags & DUMP_FLAG_NO_CALL_NO)) {
+            os << call->no << " ";
+        }
 
         if (callFlags & CALL_FLAG_NON_REPRODUCIBLE) {
             os << strike;
@@ -252,7 +256,6 @@ void dump(Value *value, std::ostream &os, DumpFlags flags) {
 
 void dump(Call &call, std::ostream &os, DumpFlags flags) {
     Dumper d(os, flags);
-    os << call.no << " ";
     d.visit(&call);
 }
 

diff --git a/common/trace_dump.hpp b/common/trace_dump.hpp
index 4ffe65ac09b460f3fcdbb5da8e67b277f2913de9..d4612e5599d784848202dc84ef3118826ae12369 100644 (file)
--- a/common/trace_dump.hpp
+++ b/common/trace_dump.hpp
@@ -44,6 +44,7 @@ typedef unsigned DumpFlags;
 enum {
     DUMP_FLAG_NO_COLOR                 = (1 << 0),
     DUMP_FLAG_NO_ARG_NAMES             = (1 << 1),
+    DUMP_FLAG_NO_CALL_NO               = (1 << 2),
 };
 
 

diff --git a/glretrace.py b/glretrace.py
index 7570ebde957822cab1a3f35ae606e7be549cbfa9..e862e25a3757b9c99ad94d7f556abcfd3dbee8e9 100644 (file)
--- a/glretrace.py
+++ b/glretrace.py
@@ -240,7 +240,7 @@ class GlRetracer(Retracer):
             print '    glretrace::insideGlBeginEnd = true;'
         elif function.name.startswith('gl'):
             # glGetError is not allowed inside glBegin/glEnd
-            print '    if (!glretrace::benchmark && !glretrace::insideGlBeginEnd) {'
+            print '    if (!glretrace::benchmark && !retrace::profiling && !glretrace::insideGlBeginEnd) {'
             print '        glretrace::checkGlError(call);'
             if function.name in ('glProgramStringARB', 'glProgramStringNV'):
                 print r'        GLint error_position = -1;'

diff --git a/glretrace_main.cpp b/glretrace_main.cpp
index f9d77413eef276c8513aa294c19af90238745934..785d6feaadf6bdbf90b4c359958b7478f2254315 100644 (file)
--- a/glretrace_main.cpp
+++ b/glretrace_main.cpp
@@ -256,7 +256,7 @@ static void display(void) {
     long long endTime = os::getTime();
     float timeInterval = (endTime - startTime) * (1.0 / os::timeFrequency);
 
-    if (retrace::verbosity >= -1) { 
+    if ((retrace::verbosity >= -1) || (retrace::profiling)) {
         std::cout << 
             "Rendered " << frame << " frames"
             " in " <<  timeInterval << " secs,"
@@ -277,6 +277,7 @@ static void usage(void) {
         "Replay TRACE.\n"
         "\n"
         "  -b           benchmark mode (no error checking or warning messages)\n"
+        "  -p           profiling mode (run whole trace, dump profiling info)\n"
         "  -c PREFIX    compare against snapshots\n"
         "  -C CALLSET   calls to compare (default is every frame)\n"
         "  -core        use core profile\n"
@@ -309,6 +310,10 @@ int main(int argc, char **argv)
             benchmark = true;
             retrace::verbosity = -1;
             glws::debug = false;
+        } else if (!strcmp(arg, "-p")) {
+            retrace::profiling = true;
+            retrace::verbosity = -1;
+            glws::debug = false;
         } else if (!strcmp(arg, "-c")) {
             compare_prefix = argv[++i];
             if (compare_frequency.empty()) {

diff --git a/retrace.cpp b/retrace.cpp
index 849c597f10cafaf64ef12b6d19a9266eab7b393b..d2e6d379b06d283ca729e1712e80a22044103189 100644 (file)
--- a/retrace.cpp
+++ b/retrace.cpp
@@ -27,6 +27,7 @@
 #include <string.h>
 #include <iostream>
 
+#include "os_time.hpp"
 #include "trace_dump.hpp"
 #include "retrace.hpp"
 
@@ -35,6 +36,7 @@ namespace retrace {
 
 
 int verbosity = 0;
+bool profiling = false;
 
 
 static bool call_dumped = false;
@@ -114,7 +116,20 @@ void Retracer::retrace(trace::Call &call) {
     assert(callback);
     assert(callbacks[id] == callback);
 
-    callback(call);
+    if (retrace::profiling) {
+        long long startTime = os::getTime();
+        callback(call);
+        long long stopTime = os::getTime();
+        float timeInterval = (stopTime - startTime) * (1.0E6 / os::timeFrequency);
+
+        std::cout
+            << call.no << " "
+            << "[" << timeInterval << " usec] "
+        ;
+        trace::dump(call, std::cout, trace::DUMP_FLAG_NO_CALL_NO | trace::DUMP_FLAG_NO_COLOR);
+    } else {
+        callback(call);
+    }
 }
 
 

diff --git a/retrace.hpp b/retrace.hpp
index a59a6eb8901e97195d2f268082101a331396881b..57b8b052639085e6b8742bd5e395761f999577fe 100644 (file)
--- a/retrace.hpp
+++ b/retrace.hpp
@@ -95,6 +95,11 @@ toPointer(trace::Value &value, bool bind = false);
  */
 extern int verbosity;
 
+/**
+ * Add profiling data to the dump when retracing.
+ */
+extern bool profiling;
+
 
 std::ostream &warning(trace::Call &call);