#include <string.h>
-#include "os_binary.hpp"
-#include "os_string.hpp"
-#include "os_time.hpp"
-#include "image.hpp"
#include "retrace.hpp"
-#include "trace_callset.hpp"
#include "glproc.hpp"
#include "glstate.hpp"
#include "glretrace.hpp"
+#include "os_time.hpp"
+/* Synchronous debug output may reduce performance however,
+ * without it the callNo in the callback may be inaccurate
+ * as the callback may be called at any time.
+ */
+#define DEBUG_OUTPUT_SYNCHRONOUS 0
namespace glretrace {
-bool double_buffer = true;
+bool insideList = false;
bool insideGlBeginEnd = false;
-glws::Profile defaultProfile = glws::PROFILE_COMPAT;
-glws::Visual *visual[glws::PROFILE_MAX];
-glws::Drawable *drawable = NULL;
-glws::Context *context = NULL;
-unsigned frame = 0;
-long long startTime = 0;
-bool wait = false;
+struct CallQuery
+{
+ GLuint ids[3];
+ unsigned call;
+ bool isDraw;
+ GLuint program;
+ const trace::FunctionSig *sig;
+ int64_t cpuStart;
+ int64_t cpuEnd;
+};
-bool benchmark = false;
-static const char *compare_prefix = NULL;
-static const char *snapshot_prefix = NULL;
-static trace::CallSet snapshot_frequency;
-static trace::CallSet compare_frequency;
+static bool supportsElapsed = true;
+static bool supportsTimestamp = true;
+static bool supportsOcclusion = true;
+static bool supportsDebugOutput = true;
-unsigned dump_state = ~0;
+static std::list<CallQuery> callQueries;
+
+static void APIENTRY
+debugOutputCallback(GLenum source, GLenum type, GLuint id, GLenum severity, GLsizei length, const GLchar* message, GLvoid* userParam);
void
checkGlError(trace::Call &call) {
os << "\n";
}
-/**
- * Grow the current drawble.
- *
- * We need to infer the drawable size from GL calls because the drawable sizes
- * are specified by OS specific calls which we do not trace.
- */
-void
-updateDrawable(int width, int height) {
- if (!drawable) {
- return;
- }
+static void
+getCurrentTimes(int64_t& cpuTime, int64_t& gpuTime) {
+ GLuint query;
- if (drawable->visible &&
- width <= drawable->width &&
- height <= drawable->height) {
- return;
+ if (retrace::profilingGpuTimes && supportsTimestamp) {
+ glGenQueries(1, &query);
+ glQueryCounter(query, GL_TIMESTAMP);
+ glGetQueryObjecti64vEXT(query, GL_QUERY_RESULT, &gpuTime);
+ } else {
+ gpuTime = 0;
}
- // Ignore zero area viewports
- if (width == 0 || height == 0) {
- return;
+ if (retrace::profilingCpuTimes) {
+ cpuTime = os::getTime();
+ } else {
+ cpuTime = 0;
}
- // Check for bound framebuffer last, as this may have a performance impact.
- GLint draw_framebuffer = 0;
- glGetIntegerv(GL_DRAW_FRAMEBUFFER_BINDING, &draw_framebuffer);
- if (draw_framebuffer != 0) {
- return;
+ if (retrace::profilingGpuTimes && supportsTimestamp) {
+ glDeleteQueries(1, &query);
}
+}
- drawable->resize(width, height);
- drawable->show();
+static void
+completeCallQuery(CallQuery& query) {
+ /* Get call start and duration */
+ int64_t gpuStart = 0, gpuDuration = 0, cpuDuration = 0, pixels = 0;
+
+ if (query.isDraw) {
+ if (retrace::profilingGpuTimes) {
+ if (supportsTimestamp) {
+ glGetQueryObjecti64vEXT(query.ids[0], GL_QUERY_RESULT, &gpuStart);
+ }
- glScissor(0, 0, width, height);
-}
+ glGetQueryObjecti64vEXT(query.ids[1], GL_QUERY_RESULT, &gpuDuration);
+ }
+ if (retrace::profilingPixelsDrawn) {
+ glGetQueryObjecti64vEXT(query.ids[2], GL_QUERY_RESULT, &pixels);
+ }
-static void
-snapshot(unsigned call_no) {
- assert(snapshot_prefix || compare_prefix);
+ glDeleteQueries(3, query.ids);
+ } else {
+ pixels = -1;
+ }
- if (!drawable) {
- return;
+ if (retrace::profilingCpuTimes) {
+ cpuDuration = query.cpuEnd - query.cpuStart;
+ }
+
+ /* Add call to profile */
+ retrace::profiler.addCall(query.call, query.sig->name, query.program, pixels, gpuStart, gpuDuration, query.cpuStart, cpuDuration);
+}
+
+void
+flushQueries() {
+ for (std::list<CallQuery>::iterator itr = callQueries.begin(); itr != callQueries.end(); ++itr) {
+ completeCallQuery(*itr);
}
- image::Image *ref = NULL;
+ callQueries.clear();
+}
+
+void
+beginProfile(trace::Call &call, bool isDraw) {
+ /* Create call query */
+ CallQuery query;
+ query.isDraw = isDraw;
+ query.call = call.no;
+ query.sig = call.sig;
+ query.program = glretrace::currentContext ? glretrace::currentContext->activeProgram : 0;
+
+ /* GPU profiling only for draw calls */
+ if (isDraw) {
+ glGenQueries(3, query.ids);
+
+ if (retrace::profilingGpuTimes) {
+ if (supportsTimestamp) {
+ glQueryCounter(query.ids[0], GL_TIMESTAMP);
+ }
- if (compare_prefix) {
- os::String filename = os::String::format("%s%010u.png", compare_prefix, call_no);
- ref = image::readPNG(filename);
- if (!ref) {
- return;
+ glBeginQuery(GL_TIME_ELAPSED, query.ids[1]);
}
- if (retrace::verbosity >= 0) {
- std::cout << "Read " << filename << "\n";
+
+ if (retrace::profilingPixelsDrawn) {
+ glBeginQuery(GL_SAMPLES_PASSED, query.ids[2]);
}
}
- image::Image *src = glstate::getDrawBufferImage();
- if (!src) {
- return;
- }
+ callQueries.push_back(query);
- if (snapshot_prefix) {
- if (snapshot_prefix[0] == '-' && snapshot_prefix[1] == 0) {
- char comment[21];
- snprintf(comment, sizeof comment, "%u", call_no);
- src->writePNM(std::cout, comment);
- } else {
- os::String filename = os::String::format("%s%010u.png", snapshot_prefix, call_no);
- if (src->writePNG(filename) && retrace::verbosity >= 0) {
- std::cout << "Wrote " << filename << "\n";
- }
- }
+ /* CPU profiling for all calls */
+ if (retrace::profilingCpuTimes) {
+ callQueries.back().cpuStart = os::getTime();
}
+}
- if (ref) {
- std::cout << "Snapshot " << call_no << " average precision of " << src->compare(*ref) << " bits\n";
- delete ref;
+void
+endProfile(trace::Call &call, bool isDraw) {
+ GLint64 time = os::getTime();
+
+ /* CPU profiling for all calls */
+ if (retrace::profilingCpuTimes) {
+ CallQuery& query = callQueries.back();
+ query.cpuEnd = time;
}
- delete src;
+ /* GPU profiling only for draw calls */
+ if (isDraw) {
+ if (retrace::profilingGpuTimes) {
+ glEndQuery(GL_TIME_ELAPSED);
+ }
+
+ if (retrace::profilingPixelsDrawn) {
+ glEndQuery(GL_SAMPLES_PASSED);
+ }
+ }
}
+void
+initContext() {
+ const char* extensions = (const char*)glGetString(GL_EXTENSIONS);
+
+ /* Ensure we have adequate extension support */
+ supportsTimestamp = glws::checkExtension("GL_ARB_timer_query", extensions);
+ supportsElapsed = glws::checkExtension("GL_EXT_timer_query", extensions) || supportsTimestamp;
+ supportsOcclusion = glws::checkExtension("GL_ARB_occlusion_query", extensions);
+ supportsDebugOutput = glws::checkExtension("GL_ARB_debug_output", extensions);
+
+ /* Check for timer query support */
+ if (retrace::profilingGpuTimes) {
+ if (!supportsTimestamp && !supportsElapsed) {
+ std::cout << "Error: Cannot run profile, GL_EXT_timer_query extension is not supported." << std::endl;
+ exit(-1);
+ }
-void frame_complete(trace::Call &call) {
- ++frame;
+ GLint bits = 0;
+ glGetQueryiv(GL_TIME_ELAPSED, GL_QUERY_COUNTER_BITS, &bits);
- if (!drawable) {
- return;
+ if (!bits) {
+ std::cout << "Error: Cannot run profile, GL_QUERY_COUNTER_BITS == 0." << std::endl;
+ exit(-1);
+ }
}
- if (!drawable->visible) {
- retrace::warning(call) << "could not infer drawable size (glViewport never called)\n";
+ /* Check for occlusion query support */
+ if (retrace::profilingPixelsDrawn && !supportsOcclusion) {
+ std::cout << "Error: Cannot run profile, GL_ARB_occlusion_query extension is not supported." << std::endl;
+ exit(-1);
}
-}
+ /* Setup debug message call back */
+ if (retrace::debug && supportsDebugOutput) {
+ glDebugMessageCallbackARB(&debugOutputCallback, currentContext);
-static void display(void) {
- retrace::Retracer retracer;
-
- retracer.addCallbacks(gl_callbacks);
- retracer.addCallbacks(glx_callbacks);
- retracer.addCallbacks(wgl_callbacks);
- retracer.addCallbacks(cgl_callbacks);
- retracer.addCallbacks(egl_callbacks);
-
- startTime = os::getTime();
- trace::Call *call;
-
- while ((call = retrace::parser.parse_call())) {
- bool swapRenderTarget = call->flags & trace::CALL_FLAG_SWAP_RENDERTARGET;
- bool doSnapshot =
- snapshot_frequency.contains(*call) ||
- compare_frequency.contains(*call)
- ;
-
- // For calls which cause rendertargets to be swaped, we take the
- // snapshot _before_ swapping the rendertargets.
- if (doSnapshot && swapRenderTarget) {
- if (call->flags & trace::CALL_FLAG_END_FRAME) {
- // For swapbuffers/presents we still use this call number,
- // spite not have been executed yet.
- snapshot(call->no);
- } else {
- // Whereas for ordinate fbo/rendertarget changes we use the
- // previous call's number.
- snapshot(call->no - 1);
- }
+ if (DEBUG_OUTPUT_SYNCHRONOUS) {
+ glEnable(GL_DEBUG_OUTPUT_SYNCHRONOUS_ARB);
}
+ }
- retracer.retrace(*call);
+ /* Sync the gpu and cpu start times */
+ if (retrace::profilingCpuTimes || retrace::profilingGpuTimes) {
+ if (!retrace::profiler.hasBaseTimes()) {
+ GLint64 gpuTime, cpuTime;
- if (doSnapshot && !swapRenderTarget) {
- snapshot(call->no);
+ getCurrentTimes(cpuTime, gpuTime);
+ retrace::profiler.setBaseCpuTime(cpuTime);
+ retrace::profiler.setBaseGpuTime(gpuTime);
}
+ }
+}
- if (!insideGlBeginEnd &&
- drawable && context &&
- call->no >= dump_state) {
- glstate::dumpCurrentContext(std::cout);
- exit(0);
+void
+frame_complete(trace::Call &call) {
+ if (retrace::profiling) {
+ /* Complete any remaining queries */
+ flushQueries();
+
+ /* GPU time drifts due to being relative times, not absolute and can be
+ * affected by the gpu switch between processes.
+ *
+ * To attempt to compensate we resynchronise on frame end however there is
+ * still noticeable drift within a single frame which we do not account for.
+ */
+ if (retrace::profilingCpuTimes || retrace::profilingGpuTimes) {
+ int64_t cpuTime, gpuTime, error;
+
+ getCurrentTimes(cpuTime, gpuTime);
+ cpuTime = cpuTime - retrace::profiler.getBaseCpuTime();
+ gpuTime = gpuTime - retrace::profiler.getBaseGpuTime();
+ error = gpuTime - cpuTime;
+
+ retrace::profiler.setBaseGpuTime(retrace::profiler.getBaseGpuTime() + error);
}
- delete call;
+ /* Indicate end of current frame */
+ retrace::profiler.addFrameEnd();
}
- // Reached the end of trace
- glFlush();
+ retrace::frameComplete(call);
- long long endTime = os::getTime();
- float timeInterval = (endTime - startTime) * (1.0 / os::timeFrequency);
+ if (!currentDrawable) {
+ return;
+ }
- if ((retrace::verbosity >= -1) || (retrace::profiling)) {
- std::cout <<
- "Rendered " << frame << " frames"
- " in " << timeInterval << " secs,"
- " average of " << (frame/timeInterval) << " fps\n";
+ if (retrace::debug && !currentDrawable->visible) {
+ retrace::warning(call) << "could not infer drawable size (glViewport never called)\n";
}
+}
- if (wait) {
- while (glws::processEvents()) {}
- } else {
- exit(0);
+static const char*
+getDebugOutputSource(GLenum source) {
+ switch(source) {
+ case GL_DEBUG_SOURCE_API_ARB:
+ return "API";
+ case GL_DEBUG_SOURCE_WINDOW_SYSTEM_ARB:
+ return "Window System";
+ case GL_DEBUG_SOURCE_SHADER_COMPILER_ARB:
+ return "Shader Compiler";
+ case GL_DEBUG_SOURCE_THIRD_PARTY_ARB:
+ return "Third Party";
+ case GL_DEBUG_SOURCE_APPLICATION_ARB:
+ return "Application";
+ case GL_DEBUG_SOURCE_OTHER_ARB:
+ default:
+ return "";
}
}
+static const char*
+getDebugOutputType(GLenum type) {
+ switch(type) {
+ case GL_DEBUG_TYPE_ERROR_ARB:
+ return "error";
+ case GL_DEBUG_TYPE_DEPRECATED_BEHAVIOR_ARB:
+ return "deprecated behaviour";
+ case GL_DEBUG_TYPE_UNDEFINED_BEHAVIOR_ARB:
+ return "undefined behaviour";
+ case GL_DEBUG_TYPE_PORTABILITY_ARB:
+ return "portability issue";
+ case GL_DEBUG_TYPE_PERFORMANCE_ARB:
+ return "performance issue";
+ case GL_DEBUG_TYPE_OTHER_ARB:
+ default:
+ return "unknown issue";
+ }
+}
-static void usage(void) {
- std::cout <<
- "Usage: glretrace [OPTION] TRACE\n"
- "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"
- " -db use a double buffer visual (default)\n"
- " -sb use a single buffer visual\n"
- " -s PREFIX take snapshots; `-` for PNM stdout output\n"
- " -S CALLSET calls to snapshot (default is every frame)\n"
- " -v increase output verbosity\n"
- " -D CALLNO dump state at specific call no\n"
- " -w wait on final frame\n";
+static const char*
+getDebugOutputSeverity(GLenum severity) {
+ switch(severity) {
+ case GL_DEBUG_SEVERITY_HIGH_ARB:
+ return "High";
+ case GL_DEBUG_SEVERITY_MEDIUM_ARB:
+ return "Medium";
+ case GL_DEBUG_SEVERITY_LOW_ARB:
+ return "Low";
+ default:
+ return "usnknown";
+ }
}
-extern "C"
-int main(int argc, char **argv)
-{
- assert(compare_frequency.empty());
- assert(snapshot_frequency.empty());
+static void APIENTRY
+debugOutputCallback(GLenum source, GLenum type, GLuint id, GLenum severity, GLsizei length, const GLchar* message, GLvoid* userParam) {
+ std::cerr << retrace::callNo << ": ";
+ std::cerr << "glDebugOutputCallback: ";
+ std::cerr << getDebugOutputSeverity(severity) << " severity ";
+ std::cerr << getDebugOutputSource(source) << " " << getDebugOutputType(type);
+ std::cerr << " " << id;
+ std::cerr << ", " << message;
+ std::cerr << std::endl;
+}
- int i;
- for (i = 1; i < argc; ++i) {
- const char *arg = argv[i];
+} /* namespace glretrace */
- if (arg[0] != '-') {
- break;
- }
-
- if (!strcmp(arg, "--")) {
- break;
- } else if (!strcmp(arg, "-b")) {
- 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()) {
- compare_frequency = trace::CallSet(trace::FREQUENCY_FRAME);
- }
- } else if (!strcmp(arg, "-C")) {
- compare_frequency = trace::CallSet(argv[++i]);
- if (compare_prefix == NULL) {
- compare_prefix = "";
- }
- } else if (!strcmp(arg, "-D")) {
- dump_state = atoi(argv[++i]);
- retrace::verbosity = -2;
- } else if (!strcmp(arg, "-core")) {
- defaultProfile = glws::PROFILE_CORE;
- } else if (!strcmp(arg, "-db")) {
- double_buffer = true;
- } else if (!strcmp(arg, "-sb")) {
- double_buffer = false;
- } else if (!strcmp(arg, "--help")) {
- usage();
- return 0;
- } else if (!strcmp(arg, "-s")) {
- snapshot_prefix = argv[++i];
- if (snapshot_frequency.empty()) {
- snapshot_frequency = trace::CallSet(trace::FREQUENCY_FRAME);
- }
- if (snapshot_prefix[0] == '-' && snapshot_prefix[1] == 0) {
- os::setBinaryMode(stdout);
- retrace::verbosity = -2;
- }
- } else if (!strcmp(arg, "-S")) {
- snapshot_frequency = trace::CallSet(argv[++i]);
- if (snapshot_prefix == NULL) {
- snapshot_prefix = "";
- }
- } else if (!strcmp(arg, "-v")) {
- ++retrace::verbosity;
- } else if (!strcmp(arg, "-w")) {
- wait = true;
- } else {
- std::cerr << "error: unknown option " << arg << "\n";
- usage();
- return 1;
- }
- }
+void
+retrace::setUp(void) {
glws::init();
- visual[glws::PROFILE_COMPAT] = glws::createVisual(double_buffer, glws::PROFILE_COMPAT);
- visual[glws::PROFILE_CORE] = glws::createVisual(double_buffer, glws::PROFILE_CORE);
- visual[glws::PROFILE_ES1] = glws::createVisual(double_buffer, glws::PROFILE_ES1);
- visual[glws::PROFILE_ES2] = glws::createVisual(double_buffer, glws::PROFILE_ES2);
-
- for ( ; i < argc; ++i) {
- if (!retrace::parser.open(argv[i])) {
- std::cerr << "error: failed to open " << argv[i] << "\n";
- return 1;
- }
+}
- display();
- retrace::parser.close();
+void
+retrace::addCallbacks(retrace::Retracer &retracer)
+{
+ retracer.addCallbacks(glretrace::gl_callbacks);
+ retracer.addCallbacks(glretrace::glx_callbacks);
+ retracer.addCallbacks(glretrace::wgl_callbacks);
+ retracer.addCallbacks(glretrace::cgl_callbacks);
+ retracer.addCallbacks(glretrace::egl_callbacks);
+}
+
+
+image::Image *
+retrace::getSnapshot(void) {
+ if (!glretrace::currentDrawable) {
+ return NULL;
}
- for (int n = 0; n < glws::PROFILE_MAX; n++) {
- delete visual[n];
+ return glstate::getDrawBufferImage();
+}
+
+
+bool
+retrace::dumpState(std::ostream &os)
+{
+ if (glretrace::insideGlBeginEnd ||
+ !glretrace::currentDrawable ||
+ !glretrace::currentContext) {
+ return false;
}
- glws::cleanup();
+ glstate::dumpCurrentContext(os);
- return 0;
+ return true;
}
-} /* namespace glretrace */
+void
+retrace::flushRendering(void) {
+ glretrace::flushQueries();
+ glFlush();
+}
+
+void
+retrace::waitForInput(void) {
+ while (glws::processEvents()) {
+ }
+}
+
+void
+retrace::cleanUp(void) {
+ glws::cleanup();
+}
projects / apitrace / blobdiff