PipelineProfiler

From K-3D

Revision as of 16:12, 18 May 2008 by Tshead (Talk | contribs)
Jump to: navigation, search

<plugin>PipelineProfiler</plugin>

Overview

Profiling the time spent executing nodes in the K-3D Visualization Pipeline can be tricky - because the pipeline is demand-driven it is impractical for an external caller to know how much time is spent executing a node versus how much time is spent executing the node's inputs. PipelineProfiler addresses this by collecting data from individual nodes as they are executed. The data is stored as a collection of "records" that contain information about which node was executing, which sub-task within the node was executing and for how-long, automatically adjusted to eliminate time spent executing in a node's inputs. This data can be retrieved from PipelineProfiler using its "records" property.

PipelineProfiler data will typically be accessed from a Python script. The records are available in Python as a dict that maps each pipeline node to a dict. This second dict maps sub-tasks (identified using strings) to their execution time in seconds. Using this data, a caller can:

  • Determine how much time each sub-task spent executing within a node.
  • Compute a cumulative total execution time for a node.
  • Iterate over the set of profiled nodes within the document.

Examples

#python 

import k3d

# Setup a simple pipeline ...
doc = k3d.new_document()
source = doc.new_node("PolyCube")
modifier = doc.new_node("ScalePoints")
doc.set_dependency(modifier.get_property("input_mesh"), source.get_property("output_mesh"))

# Create a profiler ...
profiler = doc.new_node("PipelineProfiler")
        
# At this point the profiler should be empty ...
if len(profiler.records) != 0:
        raise Exception("expected zero profile records")

# Force execution of the pipeline ...
modifier.output_mesh
        
# At this point we expect the profiler to contain two records (one for the source and one for the modifier) ...
if len(profiler.records) != 2:
        raise Exception("expected two profile records")

# See what we've got ...
print profiler.records

The output of this script demonstrates the structure of the profiling data:

{<k3d.node object at 0xb5360374>: {'Create Mesh': 0.0018579259049147367, 'Update Mesh': 1.4108140021562576e-05, 'Convert Output': 0.0010740305297076702},
 <k3d.node object at 0xb536033c>: {'Create Mesh': 7.7021075412631035e-05, 'Update Mesh': 0.024597011506557465}}

Caveats

  • Note that PipelineProfiler only retains the most-recent execution time for each node/task pair.
  • Note that the ordering of records in the data is arbitrary.
  • Keep caching in-mind when profiling nodes. In particular, remember that most nodes cache their output until an input changes - executing a node multiple times will return misleadingly-short execution times.
  • When profiling rendering code, consider the caching that takes-place to create display lists and/or vertex buffer objects. In this case you will get misleadingly-long execution times the first-time a data set is rendered.
Personal tools