From: James Benton Date: Mon, 23 Jul 2012 14:26:54 +0000 (+0100) Subject: Improved GPU profiling code. X-Git-Url: https://git.cworth.org/git?p=apitrace;a=commitdiff_plain;h=f91056b5782d48d526f19dacd5a988003fc6f11e 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 fdc0fd4..fd684ed 100644 --- 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 19a874f..191ac72 100644 --- 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 820b4e1..2ab85e0 100644 --- 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 6dd44eb..a865b74 100644 --- 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 callQueries; -static GLuint frameQueries[2] = { 0, 0 }; +static const int maxActiveCallQueries = 256; +static std::list 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, ×tamp); - 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, ×tamp); + 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::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, ×tamp); - 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::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 164a596..2c14b87 100644 --- 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()) {