profiling_buddy/modifier_profiling.py

import bpy
from bpy.types import PropertyGroup, Operator
from bpy.props import (StringProperty,
                        FloatProperty,
                        PointerProperty,
                        CollectionProperty)

class PB_Modifier_Profiling_Panel(bpy.types.Panel):
    """
    """
    bl_label = "Modifier Profiling"
    bl_idname = "SCENE_PT_modifier_profiling"
    bl_space_type = 'PROPERTIES'
    bl_region_type = 'WINDOW'
    bl_context = "modifier"
    bl_options = {'DEFAULT_CLOSED'}

    def draw(self, context):
        layout = self.layout
        scene = context.scene
        settings = scene.profiler_buddy_prop
        
        layout.prop(settings, 'evaluation_live')
        
        if settings.evaluation_live:
            draw_modifier_times_live(self, context)
        else:
            draw_modifier_times(self, context)
            col = layout.column()
            # col.prop(settings, 'use_frame_set')
            if settings.progress >= 0:
                col.progress(factor=settings.progress / settings.evaluations_count,
                             text = f"Iteration {settings.progress}/{settings.evaluations_count}")
                ## Show modifier sub-iteration with a load ring ?
                # col.progress(factor=settings.subprogress / len(context.object.modifiers),
                #     type = 'RING') # , text = f"{settings.subprogress}/{len(context.object.modifiers)}"

            row = col.row()
            row.prop(settings, 'evaluations_count')
            row.operator('pb.evaluate', text='Evaluate')
            


def time_to_string(t):
    ''' Formats time in seconds to the nearest sensible unit.
    '''
    units = {3600.: 'h', 60.: 'm', 1.: 's', .001: 'ms'}
    for factor in units.keys():
        if t >= factor:
            return f'{t/factor:.3g} {units[factor]}'
    if t >= 1e-4:
        return f'{t/factor:.3g} {units[factor]}'
    else:
        return f'<0.1 ms'

## Dynamic draw

def draw_modifier_times_live(self, context):
    depsgraph = context.view_layer.depsgraph

    ob = context.object
    ob_eval = ob.evaluated_get(depsgraph)

    box = self.layout.box()
    times = []
    total = 0
    for mod_eval in ob_eval.modifiers:
        t = mod_eval.execution_time
        times += [t]
        total += t
    
    col_fl = box.column_flow(columns=2)
    col = col_fl.column(align=True)
    for mod_eval in ob_eval.modifiers:
        row = col.row()
        row.enabled = mod_eval.show_viewport
        row.label(text=f'{mod_eval.name}:')
    
    col = col_fl.column(align=True)
    for i, t in enumerate(times):
        row = col.row()
        row.enabled = ob_eval.modifiers[i].show_viewport
        row.alert = t >= 0.8*max(times)
        row.label(text=time_to_string(t))
    
    row = box.column_flow()
    row.column().label(text=f'TOTAL:')
    row.column().label(text=time_to_string(sum(times)))

## Static draw from dict

def draw_modifier_times(self, context):
    box = self.layout.box()

    ob = context.object
    wm = bpy.context.window_manager
    mod_timer = wm.get('mod_timer')
    if not mod_timer:
        mod_timer = wm['mod_timer'] = {}
    
    if len(ob.modifiers) == 0:
        return

    if mod_timer:
        # box.label(text=f'Average out of {context.scene.profiler_buddy_prop.evaluations_count}')
        times = [t for _m, t in mod_timer.items()]
        col_fl = box.column_flow(columns=2)
        col = col_fl.column(align=True)
        for i, (mod_name, t) in enumerate(mod_timer.items()):
            if i > len(ob.modifiers) - 1:
                continue
            row = col.row()
            row.enabled = ob.modifiers[i].show_viewport
            row.label(text=f'{mod_name}:')
        
        col = col_fl.column(align=True)
        for i, (mod_name, t) in enumerate(mod_timer.items()):
            if i > len(ob.modifiers) - 1:
                continue
            row = col.row()
            row.enabled = ob.modifiers[i].show_viewport
            row.alert = t >= 0.8*max(times)
            row.label(text=time_to_string(t))
        
        # col = col_fl.column(align=True)
        # for i, (mod_name, t) in enumerate(mod_timer.items()):
        #     if i > len(ob.modifiers) - 1:
        #         continue
        #     row = col.row()
        #     row.enabled = ob.modifiers[i].show_viewport
        #     row.alert = t >= 0.8*max(times)
        #     row.label(text=f'{1000 / (t*1000):.0f} fps')
    
        row = box.column_flow()
        
        total_time = sum(times)
        fps = f'{1000 / (total_time*1000):.1f} fps' if total_time > 0 else '-- fps'
        # row.label(text = fps)
        row.column().label(text=f'TOTAL: {fps}')

        row.column().label(text=time_to_string(total_time))
        
    
    else:
        if context.scene.profiler_buddy_prop.progress < 0:
            box.label(text='Click Evaluate To Profile Modifiers', icon='INFO')


class PB_OT_evalulate(Operator):
    bl_idname = "pb.evaluate"
    bl_label = "Evaluate Modifiers"
    bl_description = "Evaluate modifier by a count "
    bl_options = {"REGISTER"} # , "INTERNAL"

    def execute(self, context):
        wm = bpy.context.window_manager

        settings = context.scene.profiler_buddy_prop
        mod_timer = wm.get('mod_timer')
        if not mod_timer:
            mod_timer = wm['mod_timer'] = {}
        else:
            mod_timer = {}

        wm['mod_timer'].clear() # Clear dict

        tmp_dic = {}
        ob = context.object

        wm.progress_begin(0, settings.evaluations_count)
        for i in range(settings.evaluations_count):
            settings.progress = i
            bpy.ops.wm.redraw_timer(type='DRAW_WIN_SWAP', iterations=1)
            # context.area.tag_redraw()
            ob.update_tag()
            # if settings.use_frame_set:
            #     context.scene.frame_current = context.scene.frame_current

            depsgraph = context.view_layer.depsgraph
            depsgraph.update()
            ob_eval = ob.evaluated_get(depsgraph)

            ## gather a list of all evaluated sessions
            for mod_eval in ob_eval.modifiers:

                t = mod_eval.execution_time

                if i == 0:
                    # Initialize modifier dict time list
                    tmp_dic[mod_eval.name] = []

                    ## Do not store first iteration, often less precise timing
                    continue

                tmp_dic[mod_eval.name] += [t]
            
            wm.progress_update(i)

        wm.progress_end()

        settings.progress = -1

        for k, v in tmp_dic.items():
            average = sum(v) / len(v)
            # print(k, v, average)
            ## debugging
            # if settings.evaluations_count > 1:
            #     if v[0] == v[1]:
            #         print('same:')
            #     for subv in v:
            #         print(subv)

            wm['mod_timer'][k] = average

        return {"FINISHED"}


class PB_PG_modifiers_profiler(PropertyGroup):
    evaluation_live : bpy.props.BoolProperty(name='Live Mode', default=True)
    evaluations_count : bpy.props.IntProperty(name='Evaluations', default=5, min=2)
    progress : bpy.props.IntProperty(name='Progress', default=-1)
    # subprogress : bpy.props.IntProperty(name='ModifierProgress', default=-1)
    # use_frame_set : bpy.props.BoolProperty(name='Set Frame At Each Iteration', default=True)

classes = [
    PB_OT_evalulate,
    PB_Modifier_Profiling_Panel,
        ]


def register():
    bpy.utils.register_class(PB_PG_modifiers_profiler)
    bpy.types.Scene.profiler_buddy_prop = PointerProperty(type=PB_PG_modifiers_profiler)
    bpy.context.window_manager['mod_timer'] = {}
    for c in classes:
        bpy.utils.register_class(c)

def unregister():
    for c in reversed(classes):
        bpy.utils.unregister_class(c)
    bpy.utils.unregister_class(PB_PG_modifiers_profiler)
    del bpy.types.Scene.profiler_buddy_prop

if __name__ == "__main__":
    register()