Property Speed?

We’ve been using a lot of Blender Properties in our application. We’ve found that “RNA” properties are very slow (and don’t scale well with size), so we’ve tried to start using “ID” properties … which have been better. But there still seems to be a scaling problem with them as well.

As an example, I wrote a small addon (included below) that just loops while adding elements to a dictionary and records the amount of time it takes. In the pure Python case (running in a Blender Addon, of course), I use a regular python dictionary:

s = {}
for i in range(int(numsamps)):
    s['a'+str(i)] = 2 * i

In the Blender case, I create the dictionary as a Blender ID property and perform the exact same operations:

bpy.context.scene['s'] = {}
s = bpy.context.scene['s']
for i in range(int(numsamps)):
    s['a'+str(i)] = 2 * i

Here are the results for different numbers of passes (given in seconds):

[TABLE=“class: grid, width: 500, align: center”]

Passes
Python
Blender

5000
0.01
0.08

10000
0.01
0.33

15000
0.00
0.70

20000
0.01
1.24

25000
0.02
1.93

30000
0.02
2.77

35000
0.01
3.78

40000
0.02
5.01

45000
0.03
9.50

50000
0.03
12.51

55000
0.02
16.30

60000
0.03
22.84

[/TABLE]

In this little example, the Blender dictionary is taking over 700 times longer than the regular Python dictionary … and it gets worse as the number of samples gets larger!! More importantly, the Python dictionary is relatively flat (as a dictionary should be), but the Blender dictionary appears to be taking exponentially longer as it holds more items.

Does anyone know what’s going on?

Here’s a screen shot of my testing addon:


Here’s the full source code of my testing addon:

"""
This program compares the speed of Python and Blender Dictionaries.
"""

bl_info = {
  "version": "0.1",
  "name": "Dictionary Speed Testing",
  'author': 'BlenderHawk',
  "location": "Properties > Scene",
  "category": "Blender Experiments"
  }

import bpy
from bpy.props import *

import time


########################################################

class AppPropertyGroup(bpy.types.PropertyGroup):
    
    start_samps = IntProperty ( name="Start", min=0, default=1000, description="Starting Number of Samples" )
    stop_samps = IntProperty ( name="Stop", min=0, default=32000, description="Stopping Number of Samples" )
    step_by = FloatProperty ( name="By", min=1, default=1000, description="Step amount (added or multiplied" )
    linear = BoolProperty ( name="Linear", default=True, description="Step by addition(T) or multiplication(F)" )
    run_results = StringProperty    ( name="Run Results", default="", description="Space separated results with '~' for new row" )
    
    def clear_results (self, context):
        self.run_results = ""

    def speed_test (self, context):

        numsamps = self.start_samps
        while numsamps <= self.stop_samps:
                
            if len(self.run_results) == 0:
                # Add the header for each column
                self.run_results   = "Count Python Blender"

            self.run_results = self.run_results + "~"
            self.run_results = self.run_results + str(int(numsamps))


            print ( "Running test with " + str(int(numsamps)) + " samples..." )

            s = {}

            start = time.clock()
            for i in range(int(numsamps)):
                s['a'+str(i)] = 2 * i
            duration = time.clock() - start
            self.run_results = self.run_results + " " + "%8.6g"%duration

            print ( "  Python took  " + "%8.6g"%duration + " seconds" )

            bpy.context.scene['s'] = {}
            s = bpy.context.scene['s']

            start = time.clock()
            for i in range(int(numsamps)):
                s['a'+str(i)] = 2 * i
            duration = time.clock() - start
            self.run_results = self.run_results + " " + "%8.6g"%duration

            print ( "  Blender took " + "%8.6g"%duration + " seconds" )
            
            if self.linear:
                numsamps = numsamps + self.step_by
            else:
                numsamps = numsamps * self.step_by

        if len(self.run_results) > 0:
            print ( "===== Results =====" )        
            result_rows = self.run_results.split('~')
            for r in result_rows:
                l = ""
                result_cols = r.split()
                for c in result_cols:
                    try:
                        cf = float(c)
                        l = l + " " + "%8.6g"%cf
                    except:
                        l = l + " " + "%8s"%c
                print ( l )


    def draw_self (self, layout):
        row = layout.row()
        row.label("Speed Testing:")
        row = layout.row()
        col = row.column()
        col.prop(self,"start_samps")
        col = row.column()
        col.prop(self,"stop_samps")
        col = row.column()
        col.prop(self,"step_by")
        col = row.column()
        col.prop(self,"linear")
        row = layout.row()
        col = row.column()
        col.operator("app.speed_test", text="Run Test")
        col = row.column()
        col.operator("app.clear_results", text="Clear Results")

        if len(self.run_results) > 0:
            row = layout.row()
            row.label ( "===== Results =====" )        
            result_rows = self.run_results.split('~')
            for r in result_rows:
                row = layout.row()
                result_cols = r.split()
                for c in result_cols:
                    col = row.column()
                    col.label ( c )


########################################################

class APP_OT_clear_results_operator(bpy.types.Operator):
    bl_idname = "app.clear_results"
    bl_label = "Clear Results"
    bl_description = "Clear Results"
    bl_options = {'REGISTER'}

    def execute(self, context):
        context.scene.app.clear_results(context)
        return {'FINISHED'}

class APP_OT_speed_test_operator(bpy.types.Operator):
    bl_idname = "app.speed_test"
    bl_label = "Speed Test"
    bl_description = "Speed Test"
    bl_options = {'REGISTER'}

    def execute(self, context):
        context.scene.app.speed_test(context)
        return {'FINISHED'}

class APP_PT_Dictionary(bpy.types.Panel):
    bl_label = "Speed Testing"
    bl_space_type = "PROPERTIES"
    bl_region_type = "WINDOW"
    bl_context = "scene"
    def draw(self, context):
        context.scene.app.draw_self(self.layout)

def register():
    print ("Registering ", __name__)
    bpy.utils.register_module(__name__)
    bpy.types.Scene.app = bpy.props.PointerProperty(type=AppPropertyGroup)

def unregister():
    print ("Unregistering ", __name__)
    del bpy.types.Scene.app
    bpy.utils.unregister_module(__name__)

if __name__ == "__main__":
    register()


I modified the previous addon a bit (included below) to keep track of both dictionary creation time and dictionary access time. I also added a section for Blender Collections, so the comparison shows plain Python dictionaries (in Blender), ID Property dictionaries, and Blender CollectionProperty’s.

For the plain Python dictionary, the code to create and access looks like this:

s = python_dict = {}

# Set the values
start = time.clock()
for i in range(int(numsamps)):
    s['a'+str(i)] = 2 * i
duration = time.clock() - start

# Access the values
start = time.clock()
for i in range(int(numsamps)):
    if s['a'+str(i)] != 2 * i:
        print ( "Python Dictionary Error: " + str(s['a'+str(i)]) + " =/= " + str ( 2 * i ) )
duration = time.clock() - start

For the ID Property dictionary, the code looks like this:

bpy.context.scene['s'] = {}
s = bpy.context.scene['s']

# Set the values
start = time.clock()
for i in range(int(numsamps)):
    s['a'+str(i)] = 2 * i
duration = time.clock() - start

# Access the values
start = time.clock()
for i in range(int(numsamps)):
    if s['a'+str(i)] != 2 * i:
        print ( "Blender ID Property Error: " + str(s['a'+str(i)]) + " =/= " + str ( 2 * i ) )
duration = time.clock() - start

And for the CollectionProperty the code looks like this:

s = self.collect_prop
s.clear()

# Set the values
start = time.clock()
for i in range(int(numsamps)):
    v = s.add()
    v.name = 'a'+str(i)
    v.value = 2 * i
duration = time.clock() - start

# Access the values
start = time.clock()
for i in range(int(numsamps)):
    if s['a'+str(i)].value != 2 * i:
        print ( "Blender RNA Property Error: " + str(s['a'+str(i)].value) + " =/= " + str ( 2 * i ) )
duration = time.clock() - start

And here are the final results where “©” is table Creation, and “(A)” is table Access:

[TABLE=“class: grid, width: 500, align: center”]

   Count

Python©
Python(A)
BlenderID©
BlenderID(A)
BlenderRNA©
BlenderRNA(A)

    5000
    0.01
       0
    0.08
    0.07
    0.01
    0.74


   10000
    0.01
       0
     0.3
     0.3
    0.01
    3.02


   15000
    0.01
    0.01
    0.67
    0.66
    0.03
     7.9


   20000
    0.02
    0.01
    1.19
    1.17
    0.04
   17.52


   25000
    0.02
    0.01
    1.85
    1.83
    0.07
   31.95


   30000
    0.02
    0.01
    2.66
    2.65
    0.08
      51


   35000
    0.01
    0.02
    3.65
    3.64
    0.09
   73.99


   40000
    0.01
    0.02
     4.9
    5.11
    0.11
  100.51


   45000
    0.02
    0.02
    6.35
    6.81
    0.12
  132.07


   50000
    0.03
    0.02
    8.21
    9.04
    0.15
  166.06


   55000
    0.03
    0.02
   10.56
   11.62
    0.15
  203.77


   60000
    0.04
    0.02
    14.5
   15.65
    0.16
  245.31

[/TABLE]

You can see that plain Python Creation and Access is clearly fastest. Using Blender’s ID properties is considerably slower, and is about the same speed for both Creation and Access. Using Blender’s “RNA” Properties is relatively fast for Creation (faster than using ID Properties), but the Access time is horrible (10,000 times slower than plain Python).

I’ll include the code for this example in the next post since it exceeds the character count allowed in a single post when combined with this table.

Here’s the code used to generate the previous results:

"""
This program compares the speed of Python and Blender Dictionaries.
"""

bl_info = {
  "version": "0.1",
  "name": "Python ID RNA Speed Testing",
  'author': 'BlenderHawk',
  "location": "Properties > Scene",
  "category": "Blender Experiments"
  }

import bpy
from bpy.props import *

import time


########################################################

class NameVal ( bpy.types.PropertyGroup ):
    name = StringProperty  ( name="Name", default="" )
    value = FloatProperty ( name="Value", default=0.0 )
    def print ( self ):
        print ( "  Name = " + self.name + "  -->  " + self.value )

class AppPropertyGroup(bpy.types.PropertyGroup):
    
    start_samps = IntProperty ( name="Start", min=0, default=1000, description="Starting Number of Samples" )
    stop_samps = IntProperty ( name="Stop", min=0, default=5000, description="Stopping Number of Samples" )
    step_by = FloatProperty ( name="By", min=1, default=1000, description="Step amount (added or multiplied" )
    linear = BoolProperty ( name="Linear", default=True, description="Step by addition(T) or multiplication(F)" )
    run_results = StringProperty    ( name="Run Results", default="", description="Space separated results with '~' for new row" )

    collect_prop = CollectionProperty ( type=NameVal )

    def clear_results (self, context):
        self.run_results = ""
        bpy.context.scene['s'] = {}
        self.collect_prop.clear()

    def speed_test (self, context):

        numsamps = self.start_samps
        while numsamps <= self.stop_samps:
                
            if len(self.run_results) == 0:
                # Add the header for each column
                self.run_results   = "Count Python(C) Python(A) BlenderID(C) BlenderID(A) BlenderRNA(C) BlenderRNA(A)"

            self.run_results = self.run_results + "~"
            self.run_results = self.run_results + str(int(numsamps))


            print ( "Running test with " + str(int(numsamps)) + " samples..." )

            s = python_dict = {}

            # Set the values
            start = time.clock()
            for i in range(int(numsamps)):
                s['a'+str(i)] = 2 * i
            duration = time.clock() - start
            self.run_results = self.run_results + " " + "%8.6g"%duration

            # Access the values
            start = time.clock()
            for i in range(int(numsamps)):
                if s['a'+str(i)] != 2 * i:
                    print ( "Python Dictionary Error: " + str(s['a'+str(i)]) + " =/= " + str ( 2 * i ) )
            duration = time.clock() - start
            self.run_results = str(self.run_results).strip() + " " + ("%8.6g"%duration).strip()

            print ( "  Python took  " + "%8.6g"%duration + " seconds" )


            bpy.context.scene['s'] = {}
            s = bpy.context.scene['s']

            # Set the values
            start = time.clock()
            for i in range(int(numsamps)):
                s['a'+str(i)] = 2 * i
            duration = time.clock() - start
            self.run_results = self.run_results + " " + "%8.6g"%duration

            # Access the values
            start = time.clock()
            for i in range(int(numsamps)):
                if s['a'+str(i)] != 2 * i:
                    print ( "Blender ID Property Error: " + str(s['a'+str(i)]) + " =/= " + str ( 2 * i ) )
            duration = time.clock() - start
            self.run_results = str(self.run_results).strip() + " " + ("%8.6g"%duration).strip()

            print ( "  Blender ID took " + "%8.6g"%duration + " seconds" )


            s = self.collect_prop
            s.clear()

            # Set the values
            start = time.clock()
            for i in range(int(numsamps)):
                v = s.add()
                v.name = 'a'+str(i)
                v.value = 2 * i
            duration = time.clock() - start
            self.run_results = self.run_results + " " + "%8.6g"%duration

            # Access the values
            start = time.clock()
            for i in range(int(numsamps)):
                if s['a'+str(i)].value != 2 * i:
                    print ( "Blender RNA Property Error: " + str(s['a'+str(i)].value) + " =/= " + str ( 2 * i ) )
            duration = time.clock() - start
            self.run_results = str(self.run_results).strip() + " " + ("%8.6g"%duration).strip()

            print ( "  Blender RNA took " + "%8.6g"%duration + " seconds" )


            if self.linear:
                numsamps = numsamps + self.step_by
            else:
                numsamps = numsamps * self.step_by


        if len(self.run_results) > 0:
            print ( "===== Results (BBCode Table Format) =====" )   
            print ( "[TABLE="width: 500"]

" + "%12.6g"%cf + "
" + "%12s"%(c.replace("/"," / ")) + "

[/TABLE]
" )
            print ( "
" )

            print ( "===== Results =====" )        
            result_rows = self.run_results.split('~')
            for r in result_rows:
                l = ""
                result_cols = r.split()
                for c in result_cols:
                    try:
                        cf = float(c)
                        l = l + " " + "%12.6g"%cf
                    except:
                        l = l + " " + "%12s"%(c.replace("/"," / "))
                print ( l )


    def draw_self (self, layout):
        row = layout.row()
        row.label("Speed Testing:")
        row = layout.row()
        col = row.column()
        col.prop(self,"start_samps")
        col = row.column()
        col.prop(self,"stop_samps")
        col = row.column()
        col.prop(self,"step_by")
        col = row.column()
        col.prop(self,"linear")
        row = layout.row()
        col = row.column()
        col.operator("app.speed_test", text="Run Test")
        col = row.column()
        col.operator("app.clear_results", text="Clear Results")

        if len(self.run_results) > 0:
            row = layout.row()
            row.label ( "===== Results (creation/access) =====" )        
            result_rows = self.run_results.split('~')
            for r in result_rows:
                row = layout.row()
                result_cols = r.split()
                for c in result_cols:
                    col = row.column()
                    col.label ( c.replace("/"," / ") )


########################################################

class APP_OT_clear_results_operator(bpy.types.Operator):
    bl_idname = "app.clear_results"
    bl_label = "Clear Results"
    bl_description = "Clear Results"
    bl_options = {'REGISTER'}

    def execute(self, context):
        context.scene.app.clear_results(context)
        return {'FINISHED'}

class APP_OT_speed_test_operator(bpy.types.Operator):
    bl_idname = "app.speed_test"
    bl_label = "Speed Test"
    bl_description = "Speed Test"
    bl_options = {'REGISTER'}

    def execute(self, context):
        context.scene.app.speed_test(context)
        return {'FINISHED'}

class APP_PT_Dictionary(bpy.types.Panel):
    bl_label = "Speed Testing"
    bl_space_type = "PROPERTIES"
    bl_region_type = "WINDOW"
    bl_context = "scene"
    def draw(self, context):
        context.scene.app.draw_self(self.layout)

def register():
    print ("Registering ", __name__)
    bpy.utils.register_module(__name__)
    bpy.types.Scene.app = bpy.props.PointerProperty(type=AppPropertyGroup)

def unregister():
    print ("Unregistering ", __name__)
    del bpy.types.Scene.app
    bpy.utils.unregister_module(__name__)

if __name__ == "__main__":
    register()

I also ran a version where I substituted a “get” call in place of the dictionary “[]” syntax for the CollectionProperty access:

Changing this:

  if s['a'+str(i)].value != 2 * i:

To this:

  if s.get('a'+str(i)).value != 2 * i:

The results were pretty much the same.

This does seem to work.


bpy.context.scene['s'] = s

Just do your work with the faster dictionary then store it in property. It is the repeated access to the property that is slow.

the reason why it doesn’t scale in constant or linear, is probably because all properties are iterated until the right one is found (a b-tree, skiplist, hash table or similar technique would probably be able to speed it up a lot)

And why in the world is the Blender dictionary implemented so inefficiently? Is it implemented in C without access to something like std::map ?

Thanks. That’s essentially what I tried to do with the second version:

bpy.context.scene[‘s’] = {}
s = bpy.context.scene[‘s’]

It appears that the act of assigning a dictionary to an ID property changes it’s type:


>>> s = {}
>>> type(s)
<class 'dict'>

>>> bpy.context.scene['s'] = s
>>> type (bpy.context.scene['s'])
<class 'IDPropertyGroup'>

So I can use it as a dictionary before storing it in an ID property, but then my access (which is what I need to do most) will be through the ID property after it has been converted. I can try using the “to_dict” function to turn it back into a regular python dictionary for access, but I suspect that will be expensive to do every time I need to get at one item. I haven’t done any timing on the reverse conversion, so that might be my next approach. I’ve also done some experimenting with storing a large python dictionary “pickle” in a string property, but again the conversion time gets expensive if it has to be done every time something is needed.

Thanks for that insight. That might be a nice improvement in a future version!!

Thanks to both of you for taking the time to read all that code and respond in a thoughtful manner. BlenderArtists.org is super … and so are the helpful people who post here!!

This is becoming a bottleneck in our work. Is this a known problem that’s on anyone’s radar to hopefully be fixed soon?

Known yes, but probably not a todo… You should poke a dev on IRC.