common/trace_loader.cpp
common/trace_resource.cpp
common/trace_tools_trace.cpp
+ common/trace_profiler.cpp
common/image.cpp
common/image_bmp.cpp
common/image_pnm.cpp
--- /dev/null
+/**************************************************************************
+ *
+ * Copyright 2012 VMware, Inc.
+ * All Rights Reserved.
+ *
+ * Permission is hereby granted, free of charge, to any person obtaining a copy
+ * of this software and associated documentation files (the "Software"), to deal
+ * in the Software without restriction, including without limitation the rights
+ * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+ * copies of the Software, and to permit persons to whom the Software is
+ * furnished to do so, subject to the following conditions:
+ *
+ * The above copyright notice and this permission notice shall be included in
+ * all copies or substantial portions of the Software.
+ *
+ * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+ * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+ * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
+ * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+ * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+ * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
+ * THE SOFTWARE.
+ *
+ **************************************************************************/
+
+#include "trace_profiler.hpp"
+#include <iostream>
+
+namespace trace {
+Profiler::Profiler()
+ : baseGpuTime(0),
+ baseCpuTime(0),
+ cpuTimes(false),
+ gpuTimes(true),
+ pixelsDrawn(false)
+{
+}
+
+Profiler::~Profiler()
+{
+}
+
+void Profiler::setup(bool cpuTimes_, bool gpuTimes_, bool pixelsDrawn_)
+{
+ cpuTimes = cpuTimes_;
+ gpuTimes = gpuTimes_;
+ pixelsDrawn = pixelsDrawn_;
+
+ std::cout << "# frame_begin no gpu_start cpu_start" << std::endl;
+ std::cout << "# frame_end no gpu_end gpu_dura cpu_end cpu_dura" << std::endl;
+ std::cout << "# call no gpu_start gpu_dura cpu_start cpu_dura pixels program name" << std::endl;
+}
+
+void Profiler::addCall(unsigned no,
+ const char *name,
+ unsigned program,
+ uint64_t pixels,
+ uint64_t gpuStart, uint64_t gpuDuration,
+ uint64_t cpuStart, uint64_t cpuDuration)
+{
+ if (baseGpuTime == 0) {
+ baseGpuTime = gpuStart;
+ }
+
+ if (baseCpuTime == 0) {
+ baseCpuTime = cpuStart;
+ }
+
+ if (gpuTimes) {
+ gpuStart -= baseGpuTime;
+ } else {
+ gpuStart = 0;
+ gpuDuration = 0;
+ }
+
+ if (cpuTimes) {
+ cpuStart -= baseCpuTime;
+ } else {
+ cpuStart = 0;
+ cpuDuration = 0;
+ }
+
+ if (!pixelsDrawn) {
+ pixels = 0;
+ }
+
+ std::cout << "call"
+ << " " << no
+ << " " << gpuStart
+ << " " << gpuDuration
+ << " " << cpuStart
+ << " " << cpuDuration
+ << " " << pixels
+ << " " << program
+ << " " << name
+ << std::endl;
+}
+
+void Profiler::addFrameStart(unsigned no, uint64_t gpuStart, uint64_t cpuStart)
+{
+ if (baseGpuTime == 0) {
+ baseGpuTime = gpuStart;
+ }
+
+ if (baseCpuTime == 0) {
+ baseCpuTime = cpuStart;
+ }
+
+ if (gpuTimes) {
+ lastFrame.gpuStart = gpuStart - baseGpuTime;
+ } else {
+ lastFrame.gpuStart = 0;
+ }
+
+ if (cpuTimes) {
+ lastFrame.cpuStart = cpuStart - baseCpuTime;
+ } else {
+ lastFrame.cpuStart = 0;
+ }
+
+ lastFrame.no = no;
+
+ std::cout << "frame_begin"
+ << " " << lastFrame.no
+ << " " << lastFrame.gpuStart
+ << " " << lastFrame.cpuStart
+ << std::endl;
+}
+
+void Profiler::addFrameEnd(uint64_t gpuEnd, uint64_t cpuEnd)
+{
+ uint64_t gpuDuration, cpuDuration;
+
+ if (gpuTimes) {
+ gpuEnd -= baseGpuTime;
+ gpuDuration = gpuEnd - lastFrame.gpuStart;
+ } else {
+ gpuEnd = 0;
+ gpuDuration = 0;
+ }
+
+ if (cpuTimes) {
+ cpuEnd -= baseCpuTime;
+ cpuDuration = cpuEnd - lastFrame.cpuStart;
+ } else {
+ cpuEnd = 0;
+ cpuDuration = 0;
+ }
+
+ std::cout << "frame_end"
+ << " " << lastFrame.no
+ << " " << gpuEnd
+ << " " << gpuDuration
+ << " " << cpuEnd
+ << " " << cpuDuration
+ << std::endl;
+}
+}
--- /dev/null
+/**************************************************************************
+ *
+ * Copyright 2012 VMware, Inc.
+ * All Rights Reserved.
+ *
+ * Permission is hereby granted, free of charge, to any person obtaining a copy
+ * of this software and associated documentation files (the "Software"), to deal
+ * in the Software without restriction, including without limitation the rights
+ * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+ * copies of the Software, and to permit persons to whom the Software is
+ * furnished to do so, subject to the following conditions:
+ *
+ * The above copyright notice and this permission notice shall be included in
+ * all copies or substantial portions of the Software.
+ *
+ * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+ * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+ * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
+ * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+ * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+ * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
+ * THE SOFTWARE.
+ *
+ **************************************************************************/
+
+#ifndef TRACE_PROFILER_H
+#define TRACE_PROFILER_H
+
+#include <string>
+#include <stdint.h>
+
+namespace trace
+{
+class Profiler
+{
+public:
+ Profiler();
+ ~Profiler();
+
+ void setup(bool cpuTimes_, bool gpuTimes_, bool pixelsDrawn_);
+
+ void addFrameStart(unsigned no, uint64_t gpuStart, uint64_t cpuStart);
+ void addFrameEnd(uint64_t gpuEnd, uint64_t cpuEnd);
+
+ void addCall(unsigned no,
+ const char* name,
+ unsigned program,
+ uint64_t pixels,
+ uint64_t gpuStart, uint64_t gpuDuration,
+ uint64_t cpuStart, uint64_t cpuDuration);
+
+private:
+ uint64_t baseGpuTime;
+ uint64_t baseCpuTime;
+
+ bool cpuTimes;
+ bool gpuTimes;
+ bool pixelsDrawn;
+
+ struct {
+ unsigned no;
+ uint64_t gpuStart;
+ uint64_t cpuStart;
+ } lastFrame;
+};
+}
+
+#endif // TRACE_PROFILER_H
namespace glretrace {
+extern bool insideList;
extern bool insideGlBeginEnd;
extern const retrace::Entry wgl_callbacks[];
extern const retrace::Entry egl_callbacks[];
+void frame_start();
void frame_complete(trace::Call &call);
void updateDrawable(int width, int height);
+void flushQueries();
+void beginProfile(trace::Call &call);
+void endProfile(trace::Call &call);
+
+void setActiveProgram(GLuint program);
} /* namespace glretrace */
print r' if (pipeline) {'
print r' _pipelineHasBeenBound = true;'
print r' }'
-
+
+ profileDraw = (
+ function.name in self.draw_array_function_names or
+ function.name in self.draw_elements_function_names or
+ function.name in self.draw_indirect_function_names or
+ function.name in self.misc_draw_function_names or
+ function.name == 'glBegin'
+ )
+
+ if function.name in ('glUseProgram', 'glUseProgramObjectARB'):
+ print r' glretrace::setActiveProgram((call.arg(0)).toUInt());'
+
+ # Only profile if not inside a list as the queries get inserted into list
+ if function.name == 'glNewList':
+ print r' glretrace::insideList = true;'
+
+ if function.name == 'glEndList':
+ print r' glretrace::insideList = false;'
+
+ if profileDraw and function.name != 'glEnd':
+ print r' if (!glretrace::insideList && !glretrace::insideGlBeginEnd && retrace::profiling) {'
+ print r' glretrace::beginProfile(call);'
+ print r' }'
+
if function.name == 'glCreateShaderProgramv':
# When dumping state, break down glCreateShaderProgramv so that the
# shader source can be recovered.
else:
Retracer.invokeFunction(self, function)
+ if profileDraw or function.name == 'glEnd':
+ print r' if (!glretrace::insideList && !glretrace::insideGlBeginEnd && retrace::profiling) {'
+ print r' glretrace::endProfile(call);'
+ print r' }'
+
# Error checking
if function.name == "glBegin":
print ' glretrace::insideGlBeginEnd = true;'
#include "glproc.hpp"
#include "glstate.hpp"
#include "glretrace.hpp"
+#include "os_time.hpp"
namespace glretrace {
+bool insideList = false;
bool insideGlBeginEnd = false;
+struct CallQuery
+{
+ GLuint ids[3];
+ unsigned call;
+ GLuint program;
+ const trace::FunctionSig *sig;
+ uint64_t start;
+ uint64_t duration;
+};
+
+static bool supportsElapsed = true;
+static bool supportsTimestamp = true;
+static bool supportsOcclusion = true;
+
+static bool firstFrame = true;
+static std::list<CallQuery> callQueries;
+static std::map<glws::Context*, GLuint> activePrograms;
+
void
checkGlError(trace::Call &call) {
os << "\n";
}
+static GLuint64
+getGpuTimestamp() {
+ GLuint query = 0;
+ GLuint64 timestamp = 0;
+
+ if (retrace::profilingGpuTimes && supportsTimestamp) {
+ glGenQueries(1, &query);
+ glQueryCounter(query, GL_TIMESTAMP);
+ glGetQueryObjectui64vEXT(query, GL_QUERY_RESULT, ×tamp);
+ glDeleteQueries(1, &query);
+ }
+
+ return timestamp;
+}
+
+static GLuint64
+getCpuTimestamp() {
+ if (retrace::profilingCpuTimes) {
+ return os::getTime() * (1.0E9 / os::timeFrequency);
+ } else {
+ return 0;
+ }
+}
+
+static void
+completeCallQuery(CallQuery& query) {
+ /* Get call start and duration */
+ GLuint64 timestamp = 0, duration = 0, samples = 0;
+
+ if (retrace::profilingGpuTimes) {
+ if (supportsTimestamp) {
+ glGetQueryObjectui64vEXT(query.ids[0], GL_QUERY_RESULT, ×tamp);
+ }
+
+ if (supportsElapsed) {
+ glGetQueryObjectui64vEXT(query.ids[1], GL_QUERY_RESULT, &duration);
+ }
+ }
+
+ if (retrace::profilingPixelsDrawn && supportsOcclusion) {
+ glGetQueryObjectui64vEXT(query.ids[2], GL_QUERY_RESULT, &samples);
+ }
+
+ glDeleteQueries(3, query.ids);
+
+ /* Add call to profile */
+ retrace::profiler.addCall(query.call, query.sig->name, query.program, samples, timestamp, duration, query.start, query.duration);
+}
+
+void
+flushQueries() {
+ for (std::list<CallQuery>::iterator itr = callQueries.begin(); itr != callQueries.end(); ++itr) {
+ completeCallQuery(*itr);
+ }
+
+ callQueries.clear();
+}
+
+void setActiveProgram(GLuint program)
+{
+ activePrograms[glretrace::currentContext] = program;
+}
+
+static GLuint
+getActiveProgram()
+{
+ std::map<glws::Context*, GLuint>::iterator it;
+ it = activePrograms.find(glretrace::currentContext);
+ if (it == activePrograms.end())
+ return 0;
+
+ return it->second;
+}
+
+void
+beginProfile(trace::Call &call) {
+ if (firstFrame) {
+ /* Check for extension support */
+ const char* extensions = (const char*)glGetString(GL_EXTENSIONS);
+ GLint bits;
+
+ 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);
+
+ if (retrace::profilingGpuTimes) {
+ if (!supportsTimestamp && !supportsElapsed) {
+ std::cout << "Error: Cannot run profile, GL_EXT_timer_query extension is not supported." << std::endl;
+ exit(-1);
+ }
+
+ glGetQueryiv(GL_TIME_ELAPSED, GL_QUERY_COUNTER_BITS, &bits);
+
+ if (!bits) {
+ std::cout << "Error: Cannot run profile, GL_QUERY_COUNTER_BITS == 0." << std::endl;
+ exit(-1);
+ }
+ }
+
+ if (retrace::profilingPixelsDrawn && !supportsOcclusion) {
+ std::cout << "Error: Cannot run profile, GL_ARB_occlusion_query extension is not supported." << std::endl;
+ exit(-1);
+ }
+
+ frame_start();
+ }
+
+ /* Create call query */
+ CallQuery query;
+ query.call = call.no;
+ query.sig = call.sig;
+ query.program = getActiveProgram();
+
+ glGenQueries(3, query.ids);
+
+ if (retrace::profilingGpuTimes) {
+ if (supportsTimestamp) {
+ glQueryCounter(query.ids[0], GL_TIMESTAMP);
+ }
+
+ if (supportsElapsed) {
+ glBeginQuery(GL_TIME_ELAPSED, query.ids[1]);
+ }
+ }
+
+ if (retrace::profilingPixelsDrawn && supportsOcclusion) {
+ glBeginQuery(GL_SAMPLES_PASSED, query.ids[2]);
+ }
+
+ if (retrace::profilingCpuTimes) {
+ query.start = os::getTime();
+ }
+
+ callQueries.push_back(query);
+}
+
+void
+endProfile(trace::Call &call) {
+ if (retrace::profilingCpuTimes) {
+ CallQuery& query = callQueries.back();
+ query.duration = (os::getTime() - query.start) * (1.0E9 / os::timeFrequency);
+ }
+
+ if (retrace::profilingGpuTimes && supportsElapsed) {
+ glEndQuery(GL_TIME_ELAPSED);
+ }
+
+ if (retrace::profilingPixelsDrawn && supportsOcclusion) {
+ glEndQuery(GL_SAMPLES_PASSED);
+ }
+}
+
+void
+frame_start() {
+ firstFrame = false;
+
+ if (retrace::profiling) {
+ retrace::profiler.addFrameStart(retrace::frameNo, getGpuTimestamp(), getCpuTimestamp());
+ }
+}
+
+void
+frame_complete(trace::Call &call) {
+ if (retrace::profiling) {
+ /* Complete any remaining queries */
+ flushQueries();
+
+ /* Indicate end of current frame */
+ retrace::profiler.addFrameEnd(getGpuTimestamp(), getCpuTimestamp());
+ }
-void frame_complete(trace::Call &call) {
retrace::frameComplete(call);
+ /* Indicate start of next frame */
+ frame_start();
+
if (!currentDrawable) {
return;
}
}
}
-
} /* namespace glretrace */
void
retrace::flushRendering(void) {
+ glretrace::flushQueries();
glFlush();
}
}
}
+ flushQueries();
+
bool success = glws::makeCurrent(drawable, context);
if (!success) {
assert(callback);
assert(callbacks[id] == callback);
- 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);
- }
+ callback(call);
}
#include "trace_model.hpp"
#include "trace_parser.hpp"
+#include "trace_profiler.hpp"
namespace image {
extern trace::Parser parser;
+extern trace::Profiler profiler;
/**
* Add profiling data to the dump when retracing.
*/
extern bool profiling;
+extern bool profilingCpuTimes;
+extern bool profilingGpuTimes;
+extern bool profilingPixelsDrawn;
/**
* State dumping.
extern bool doubleBuffer;
extern bool coreProfile;
+extern unsigned frameNo;
+
std::ostream &warning(trace::Call &call);
trace::Parser parser;
+trace::Profiler profiler;
int verbosity = 0;
bool debug = true;
-bool profiling = false;
bool dumpingState = false;
-
bool doubleBuffer = true;
bool coreProfile = false;
+bool profiling = false;
+bool profilingGpuTimes = false;
+bool profilingCpuTimes = false;
+bool profilingPixelsDrawn = false;
-static unsigned frameNo = 0;
+unsigned frameNo = 0;
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"
+ " -pcpu cpu profiling (cpu times per call)\n"
+ " -pgpu gpu profiling (gpu times per draw call)\n"
+ " -ppd pixels drawn profiling (pixels drawn per draw call)\n"
" -c PREFIX compare against snapshots\n"
" -C CALLSET calls to compare (default is every frame)\n"
" -core use core profile\n"
} else if (!strcmp(arg, "-b")) {
retrace::debug = false;
retrace::verbosity = -1;
- } else if (!strcmp(arg, "-p")) {
- retrace::debug = false;
- retrace::profiling = true;
- retrace::verbosity = -1;
} else if (!strcmp(arg, "-c")) {
comparePrefix = argv[++i];
if (compareFrequency.empty()) {
++retrace::verbosity;
} else if (!strcmp(arg, "-w")) {
waitOnFinish = true;
+ } else if (arg[1] == 'p') {
+ retrace::debug = false;
+ retrace::profiling = true;
+ retrace::verbosity = -1;
+
+ if (!strcmp(arg, "-pcpu")) {
+ retrace::profilingCpuTimes = true;
+ } else if (!strcmp(arg, "-pgpu")) {
+ retrace::profilingGpuTimes = true;
+ } else if (!strcmp(arg, "-ppd")) {
+ retrace::profilingPixelsDrawn = true;
+ }
} else {
std::cerr << "error: unknown option " << arg << "\n";
usage(argv[0]);
}
retrace::setUp();
+ if (retrace::profiling) {
+ retrace::profiler.setup(retrace::profilingCpuTimes, retrace::profilingGpuTimes, retrace::profilingPixelsDrawn);
+ }
for ( ; i < argc; ++i) {
if (!retrace::parser.open(argv[i])) {
--- /dev/null
+#!/usr/bin/env python
+##########################################################################
+#
+# Copyright 2012 VMware, Inc.
+# All Rights Reserved.
+#
+# Permission is hereby granted, free of charge, to any person obtaining a copy
+# of this software and associated documentation files (the "Software"), to deal
+# in the Software without restriction, including without limitation the rights
+# to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+# copies of the Software, and to permit persons to whom the Software is
+# furnished to do so, subject to the following conditions:
+#
+# The above copyright notice and this permission notice shall be included in
+# all copies or substantial portions of the Software.
+#
+# THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+# IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+# FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
+# AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+# LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+# OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
+# THE SOFTWARE.
+#
+##########################################################################/
+
+import sys
+
+if len(sys.argv) <= 1:
+ print 'Please specify a file to read'
+ sys.exit()
+
+times = {}
+
+# frame_begin no gpu_start cpu_start
+# frame_end no gpu_end gpu_dura cpu_end cpu_dura
+# call no gpu_start gpu_dura cpu_start cpu_dura pixels program name
+
+for line in open(sys.argv[1], 'r'):
+ words = line.split(' ')
+
+ if line.startswith('#'):
+ continue
+
+ if words[0] == 'call':
+ id = long(words[1])
+ duration = long(words[3])
+ shader = long(words[7])
+ func = words[8]
+
+ if times.has_key(shader):
+ times[shader]['draws'] += 1
+ times[shader]['duration'] += duration
+
+ if duration > times[shader]['longestDuration']:
+ times[shader]['longest'] = id
+ times[shader]['longestDuration'] = duration
+ else:
+ times[shader] = {'draws': 1, 'duration': duration, 'longest': id, 'longestDuration': duration}
+
+times = sorted(times.items(), key=lambda x: x[1]['duration'], reverse=True)
+
+print '+------------+--------------+--------------------+--------------+-------------+'
+print '| Shader[id] | Draws [#] | Duration [ns] v | Per Call[ns] | Longest[id] |'
+print '+------------+--------------+--------------------+--------------+-------------+'
+
+for shader in times:
+ id = str(shader[0]).rjust(10)
+ draw = str(shader[1]['draws']).rjust(12)
+ dura = str(shader[1]['duration']).rjust(18)
+ perCall = str(shader[1]['duration'] / shader[1]['draws']).rjust(12)
+ longest = str(shader[1]['longest']).rjust(11)
+ print "| %s | %s | %s | %s | %s |" % (id, draw, dura, perCall, longest)
+
+print '+------------+--------------+--------------------+--------------+-------------+'