PipelineProfiler

From K-3D

Description

Records data profiling execution of the visualization pipeline

Plugin Status:	Experimental
Categories:	All Plugins, Experimental Plugins, Test Plugins

Metadata

Name	Value

Properties

Label	Description	Type	Script Name
Records	Contains records storing the execution time for individual node tasks.		records

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.