]> git.cworth.org Git - apitrace/commitdiff
Merge remote-tracking branch 'jbenton/master'
authorJosé Fonseca <jose.r.fonseca@gmail.com>
Mon, 6 Aug 2012 15:35:14 +0000 (16:35 +0100)
committerJosé Fonseca <jose.r.fonseca@gmail.com>
Mon, 6 Aug 2012 15:35:14 +0000 (16:35 +0100)
CMakeLists.txt
common/trace_profiler.cpp [new file with mode: 0644]
common/trace_profiler.hpp [new file with mode: 0644]
retrace/glretrace.hpp
retrace/glretrace.py
retrace/glretrace_main.cpp
retrace/glretrace_ws.cpp
retrace/retrace.cpp
retrace/retrace.hpp
retrace/retrace_main.cpp
scripts/profileshader.py [new file with mode: 0755]

index 3970f05c71d56edd3126165efc75119e23880c37..9fe20026c6e438be1778bd8fff0bf6e64d591f57 100644 (file)
@@ -295,6 +295,7 @@ add_library (common STATIC
     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
diff --git a/common/trace_profiler.cpp b/common/trace_profiler.cpp
new file mode 100644 (file)
index 0000000..02d88dc
--- /dev/null
@@ -0,0 +1,158 @@
+/**************************************************************************
+ *
+ * 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;
+}
+}
diff --git a/common/trace_profiler.hpp b/common/trace_profiler.hpp
new file mode 100644 (file)
index 0000000..c36fd77
--- /dev/null
@@ -0,0 +1,68 @@
+/**************************************************************************
+ *
+ * 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
index fea187cf05ed19b474d255bb828000d255a71464..322f06cdfdbbe38355dc9945dd38763df43a85a3 100644 (file)
@@ -33,6 +33,7 @@
 namespace glretrace {
 
 
+extern bool insideList;
 extern bool insideGlBeginEnd;
 
 
@@ -64,10 +65,16 @@ extern const retrace::Entry glx_callbacks[];
 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 */
 
 
index 08fc6a054da8bb3bd43ffa7648f30030cb731c8b..be30616d590295705da87b0e4942e27bb69063af 100644 (file)
@@ -289,7 +289,30 @@ class GlRetracer(Retracer):
             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.
@@ -321,6 +344,11 @@ class GlRetracer(Retracer):
         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;'
index 49be5054ee07b727c9262e5faf8bf21b861e64d8..cbfc67f84dcb32b3ddcf6584b6c407e9def34d17 100644 (file)
 #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) {
@@ -82,10 +102,182 @@ 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, &timestamp);
+        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, &timestamp);
+        }
+
+        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;
     }
@@ -95,7 +287,6 @@ void frame_complete(trace::Call &call) {
     }
 }
 
-
 } /* namespace glretrace */
 
 
@@ -142,6 +333,7 @@ retrace::dumpState(std::ostream &os)
 
 void
 retrace::flushRendering(void) {
+    glretrace::flushQueries();
     glFlush();
 }
 
index ceb5d7f3db9f292c93450334b84a4fea69863c93..fcaa2129dd13b3839427a623c985a128c0a19fd2 100644 (file)
@@ -121,6 +121,8 @@ makeCurrent(trace::Call &call, glws::Drawable *drawable, glws::Context *context)
         }
     }
 
+    flushQueries();
+
     bool success = glws::makeCurrent(drawable, context);
 
     if (!success) {
index 25c3f646de2dc2e5ae46f83a1ab3262c7edd4367..182d1182eece7f2768ebaf15df8de70f249e14d6 100644 (file)
@@ -112,20 +112,7 @@ void Retracer::retrace(trace::Call &call) {
     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);
 }
 
 
index a019de787cae5de55432ba2797f9355cca45c3ad..01d2609e8c9debaad11fb35b158e2f90c197818b 100644 (file)
@@ -36,6 +36,7 @@
 
 #include "trace_model.hpp"
 #include "trace_parser.hpp"
+#include "trace_profiler.hpp"
 
 
 namespace image {
@@ -47,6 +48,7 @@ namespace retrace {
 
 
 extern trace::Parser parser;
+extern trace::Profiler profiler;
 
 
 /**
@@ -146,6 +148,9 @@ extern bool debug;
  * Add profiling data to the dump when retracing.
  */
 extern bool profiling;
+extern bool profilingCpuTimes;
+extern bool profilingGpuTimes;
+extern bool profilingPixelsDrawn;
 
 /**
  * State dumping.
@@ -156,6 +161,8 @@ extern bool dumpingState;
 extern bool doubleBuffer;
 extern bool coreProfile;
 
+extern unsigned frameNo;
+
 
 std::ostream &warning(trace::Call &call);
 
index f7fb7113e4178cb757fb6eefe73a13c1c3855cdc..5f5e095a9cbe875b5bc96fa4ae97dbe06e863d71 100644 (file)
@@ -49,19 +49,22 @@ namespace retrace {
 
 
 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
@@ -194,7 +197,9 @@ usage(const char *argv0) {
         "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"
@@ -229,10 +234,6 @@ int main(int argc, char **argv)
         } 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()) {
@@ -274,6 +275,18 @@ int main(int argc, char **argv)
             ++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]);
@@ -282,6 +295,9 @@ int main(int argc, char **argv)
     }
 
     retrace::setUp();
+    if (retrace::profiling) {
+        retrace::profiler.setup(retrace::profilingCpuTimes, retrace::profilingGpuTimes, retrace::profilingPixelsDrawn);
+    }
 
     for ( ; i < argc; ++i) {
         if (!retrace::parser.open(argv[i])) {
diff --git a/scripts/profileshader.py b/scripts/profileshader.py
new file mode 100755 (executable)
index 0000000..3cfa850
--- /dev/null
@@ -0,0 +1,75 @@
+#!/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 '+------------+--------------+--------------------+--------------+-------------+'