Renderer Profiling - yvt/openspades GitHub Wiki

Since 0.1.1

OpenSpades 0.1.1 comes with a much improved CPU/GPU time profiler which can be enabled by toggling r_debugTiming to 1. Just like other config variables, it can be enabled or disabled anytime during gameplay by typing /r_debugTiming 1 or /r_debugTiming 0 into the chat window.

Real-time monitoring: Profile output is displayed over the screen like this:

Logging: Writing the profile output to the log file is supported, but it's disabled by default. Set r_debugTimingOutputLog to 1 to enable this feature. (Warning: The log file gets bloated really fast, so it’s not recommended to enable this for an extended period of time)

0.0.6-0.1.0

OpenSpades 0.0.6 has an integrated profile mechanism to find a bottleneck of the graphics render pipeline (that is, to find what makes OpenSpades run slowly). Profile output looks like:

EndScene - 46.757ms (46.642ms w/o glFinish)
  Uploading Software Rendered Stuff - 0.388ms (0.326ms w/o glFinish)
    Terrain Shadow Map - 0.223ms (0.160ms w/o glFinish)
  Shadow Map Pass - 0.066ms (0.006ms w/o glFinish)
  Sunlight Pass - 28.093ms (27.998ms w/o glFinish)
    Map - 15.210ms (2.451ms w/o glFinish)
    Model [10 model(s), 6 unique model type(s)] - 3.418ms (0.473ms w/o glFinish)
  Dynamic Light Pass [0 light(s)] - 0.353ms (0.292ms w/o glFinish)
    Map - 0.060ms (0.001ms w/o glFinish)
    Model [10 model(s), 6 unique model type(s)] - 0.064ms (0.005ms w/o glFinish)
  Debug Line - 0.064ms (0.005ms w/o glFinish)
  Water - 9.631ms (9.563ms w/o glFinish)
    Update - 2.149ms (2.085ms w/o glFinish)
      Waiting for Simulation To Done - 0.066ms (0.007ms w/o glFinish)
      Upload - 0.715ms (0.292ms w/o glFinish)
      Generate Mipmap - 0.608ms (0.196ms w/o glFinish)
      Upload Water Color Texture - 0.238ms (0.109ms w/o glFinish)
    Render - 7.256ms (7.162ms w/o glFinish)
      Preparation - 5.818ms (0.323ms w/o glFinish)
      Draw Plane - 1.102ms (0.282ms w/o glFinish)
  Post-process - 5.079ms (5.026ms w/o glFinish)
    Preparation - 0.064ms (0.005ms w/o glFinish)
    Soft Particle - 0.785ms (0.722ms w/o glFinish)
      Full Resolution - 0.100ms (0.001ms w/o glFinish)
      Low Resolution - 0.064ms (0.002ms w/o glFinish)
    Camera Blur - 0.076ms (0.017ms w/o glFinish)
    Lens Filter - 3.590ms (0.113ms w/o glFinish)
    Lens Flare - 0.052ms (0.011ms w/o glFinish)
  Copying to WM-given Framebuffer - 2.231ms (0.630ms w/o glFinish)

How to enable it?

Set r_debugTiming to 1. Remember to set it to 0 when you no longer need it.

How is it measured?

1. glFinish
2. Record the current time to A
3. Do something
4. Record the current time to B
5. glFinish
6. Record the current time to C
7. Output "BLAHBLAH - ${C-A}ms (${B-A}ms w/o glFinish)"