[PATCH 1/2] Add simple profiling support to glretrace.
Ryan C. Gordon
icculus at icculus.org
Sat Jan 7 22:32:41 PST 2012
This will note the time, in nanoseconds, that each traced call required, and
will dump this information during the replay, giving a basic idea of where
time was spent in the GL.
---
CMakeLists.txt | 2 +-
common/trace_dump.cpp | 4 ++++
common/trace_model.hpp | 7 +++++++
glretrace.hpp | 1 +
glretrace.py | 2 +-
glretrace_main.cpp | 9 ++++++++-
retrace.cpp | 29 ++++++++++++++++++++++++++++-
retrace.hpp | 5 +++++
8 files changed, 55 insertions(+), 4 deletions(-)
diff --git a/CMakeLists.txt b/CMakeLists.txt
index 6f1315a..cbc0d03 100755
--- a/CMakeLists.txt
+++ b/CMakeLists.txt
@@ -552,7 +552,7 @@ if (WIN32 OR APPLE OR X11_FOUND)
${OPENGL_gl_LIBRARY} # CGL*
)
else ()
- target_link_libraries (glretrace ${X11_X11_LIB})
+ target_link_libraries (glretrace ${X11_X11_LIB} rt)
endif ()
target_link_libraries (glretrace
diff --git a/common/trace_dump.cpp b/common/trace_dump.cpp
index 6b2fdc3..5728f02 100644
--- a/common/trace_dump.cpp
+++ b/common/trace_dump.cpp
@@ -201,6 +201,10 @@ public:
void visit(Call *call) {
CallFlags callFlags = call->flags;
+ if (callFlags & CALL_FLAG_ELAPSED) {
+ os << "[" << (((double) call->elapsed) / 1000.0) << " usec] ";
+ }
+
if (callFlags & CALL_FLAG_NON_REPRODUCIBLE) {
os << strike;
} else if (callFlags & (CALL_FLAG_FAKE | CALL_FLAG_NO_SIDE_EFFECTS)) {
diff --git a/common/trace_model.hpp b/common/trace_model.hpp
index 4f150bc..0de5820 100644
--- a/common/trace_model.hpp
+++ b/common/trace_model.hpp
@@ -403,6 +403,11 @@ enum {
* Whether this call is verbose (i.e., not usually interesting).
*/
CALL_FLAG_VERBOSE = (1 << 7),
+
+ /**
+ * Whether this call contains valid profiling information
+ */
+ CALL_FLAG_ELAPSED = (1 << 8),
};
@@ -414,6 +419,7 @@ public:
const FunctionSig *sig;
std::vector<Value *> args;
Value *ret;
+ unsigned long long elapsed;
CallFlags flags;
@@ -421,6 +427,7 @@ public:
sig(_sig),
args(_sig->num_args),
ret(0),
+ elapsed(0),
flags(_flags) {
}
diff --git a/glretrace.hpp b/glretrace.hpp
index 41e2997..d3e2589 100644
--- a/glretrace.hpp
+++ b/glretrace.hpp
@@ -54,6 +54,7 @@ enum frequency {
};
extern bool benchmark;
+extern bool profiling;
extern const char *compare_prefix;
extern const char *snapshot_prefix;
extern enum frequency snapshot_frequency;
diff --git a/glretrace.py b/glretrace.py
index 6de2882..9550414 100644
--- a/glretrace.py
+++ b/glretrace.py
@@ -248,7 +248,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 && !glretrace::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 978a34e..56a768b 100644
--- a/glretrace_main.cpp
+++ b/glretrace_main.cpp
@@ -49,6 +49,7 @@ long long startTime = 0;
bool wait = false;
bool benchmark = false;
+bool profiling = false;
const char *compare_prefix = NULL;
const char *snapshot_prefix = NULL;
enum frequency snapshot_frequency = FREQUENCY_NEVER;
@@ -232,7 +233,7 @@ static void display(void) {
long long endTime = os::getTime();
float timeInterval = (endTime - startTime) * 1.0E-6;
- if (retrace::verbosity >= -1) {
+ if ((retrace::verbosity >= -1) || (retrace::profiling)) {
std::cout <<
"Rendered " << frame << " frames"
" in " << timeInterval << " secs,"
@@ -253,6 +254,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"
" -core use core profile\n"
" -db use a double buffer visual (default)\n"
@@ -282,6 +284,11 @@ int main(int argc, char **argv)
benchmark = true;
retrace::verbosity = -1;
glws::debug = false;
+ } else if (!strcmp(arg, "-p")) {
+ profiling = true;
+ retrace::profiling = true;
+ retrace::verbosity = -1;
+ glws::debug = false;
} else if (!strcmp(arg, "-c")) {
compare_prefix = argv[++i];
if (snapshot_frequency == FREQUENCY_NEVER) {
diff --git a/retrace.cpp b/retrace.cpp
index 849c597..73496f0 100644
--- a/retrace.cpp
+++ b/retrace.cpp
@@ -26,6 +26,8 @@
#include <string.h>
#include <iostream>
+#include <sys/time.h>
+#include <time.h>
#include "trace_dump.hpp"
#include "retrace.hpp"
@@ -35,6 +37,7 @@ namespace retrace {
int verbosity = 0;
+bool profiling = false;
static bool call_dumped = false;
@@ -80,6 +83,22 @@ void Retracer::addCallbacks(const Entry *entries) {
}
}
+static inline unsigned long long now()
+{
+#ifdef __linux__ // !!! FIXME: and others?
+ struct timespec tp;
+ if (clock_gettime(CLOCK_REALTIME, &tp) == -1)
+ return 0;
+ return (((unsigned long long) tp.tv_sec) * 1000000000ull) + ((unsigned long long) tp.tv_nsec);
+#elif defined(__APPLE__) || defined(unix) // !!! FIXME: is there something higher resolution without resorting to RDSTC?
+ struct timeval tv;
+ gettimeofday(&tv, NULL);
+ return (((unsigned long long) tv.tv_sec) * 1000000000ull) + (((unsigned long long) tv.tv_usec) * 1000ull);
+#else
+# warning no profiling support on this platform. Write me!
+ return 0;
+#endif
+}
void Retracer::retrace(trace::Call &call) {
call_dumped = false;
@@ -114,8 +133,16 @@ void Retracer::retrace(trace::Call &call) {
assert(callback);
assert(callbacks[id] == callback);
+ const unsigned long long start = retrace::profiling ? now() : 0;
+
callback(call);
-}
+ if (retrace::profiling) {
+ call.elapsed = (unsigned long long) (now() - start);
+ call.flags |= trace::CALL_FLAG_ELAPSED;
+ trace::dump(call, std::cout, trace::DUMP_FLAG_NO_COLOR);
+ }
+}
} /* namespace retrace */
+
diff --git a/retrace.hpp b/retrace.hpp
index a59a6eb..57b8b05 100644
--- 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);
--
1.7.5.4
--------------080702070303060002060108--
More information about the apitrace
mailing list