Skip to main content
added 2263 characters in body
Source Link
Fox
  • 2.1k
  • 22
  • 49

#TODO: cProfile filter plugin modules only?
#TODO: cProfile real time printing maybe?
#TODO: create a plugin out of this 


#   .oooooo.   ooooooooo.                       .o88o.  o8o  oooo
#  d8P'  `Y8b  `888   `Y88.                     888 `"  `"'  `888
# 888           888   .d88' oooo d8b  .ooooo.  o888oo  oooo   888   .ooooo.
# 888           888ooo88P'  `888""8P d88' `88b  888    `888   888  d88' `88b
# 888           888          888     888   888  888     888   888  888ooo888
# `88b    ooo   888          888     888   888  888     888   888  888    .o
#  `Y8bood8P'  o888o        d888b    `Y8bod8P' o888o   o888o o888o `Y8bod8P'

 

class cProfiler: 

    app = None

    #HomebrewedProfiler#EventProfiler Parmeters: 

    #print stats to console?
    outputprint = False 

    #updatelog, will overwrite old log
    outputlog = True 

    #log name
    logname = "profile"

    #try to run vizualisation sofware?
    runviz = True 

    #snakeviz|tuna ? use "pip install x" first
    vizapp = "snakeviz" 


    @classmethod
    def start(cls):

        import cProfile

        print("\n","Starting cProfiler","\n")
        cls.app = cProfile.Profile()
        cls.app.enable()

        return None

    @classmethod
    def end(cls,):

        if (cls.app is None): 
            return None

        print("\n","Ending cProfiler","\n")

        import pstats
        import io 

        cls.app.disable()
        s = io.StringIO()
        ps = pstats.Stats(cls.app, stream=s).sort_stats(pstats.SortKey.CUMULATIVE)

        if (cls.outputlog or cls.runviz):
            
            import os
            import bpy
                    
            filename = "cprofilerf"{cls.logname}.log"
            localpath = os.path.dirname(bpy.utils.resource_path("LOCAL"))
            path = os.path.join(localpath,filename)

            print("\n",f"cProfiler Dumping Stats : {path}","\n")
            ps.dump_stats(path)

            if cls.runviz:

                import shlex
                import subprocess

                command = f"python -m {cls.vizapp} {filename}"
                print("\n",f"Trying to run {cls.vizapp.title()} : {command}","\n")

                try:
                    #os.system(command)
                    subprocess.Popen(shlex.split(command))
                
                except Exception as e: 

                    print("\n","VizApp failed, did you tried pip install?\nif so please check our source code and see if your OS is properly supported","\n")
        
        if cls.outputprint:

            ps.print_stats()
            print(s.getvalue())

        return None



# ooooo   ooooo                                                                         .o8
# `888'   `888'                                                                        "888
#  888     888   .ooooo.  ooo. .oo.  .oo.    .ooooo.  ooo. .oo.  .oo.    .oooo.    .oooo888   .ooooo.
#  888ooooo888  d88' `88b `888P"Y88bP"Y88b  d88' `88b `888P"Y88bP"Y88b  `P  )88b  d88' `888  d88' `88b
#  888     888  888   888  888   888   888  888ooo888  888   888   888   .oP"888  888   888  888ooo888
#  888     888  888   888  888   888   888  888    .o  888   888   888  d8(  888  888   888  888    .o
# o888o   o888o `Y8bod8P' o888o o888o o888o `Y8bod8P' o888o o888o o888o `Y888""8o `Y8bod88P" `Y8bod8P'

# This version still need more work,
# wrapping is very tricky


class HomebrewedProfilerEventProfiler: 

    #main registry 
    registry = {}

    #HomebrewedProfiler#EventProfiler Parmeters: 

    #please define your plugin main module here, it should be the name of your folder
    plugin_main_module = ""

    #print all event?
    event_prints = True
    print_extra_info = False

    #end() parameter
    outputprint=True

    #ignore parameters, typically ui functions/modules
    ignore_fcts = []
    ignore_module = []

    @classmethod
    def register(cls, fct, exec_time=0):
        """update internal registry with exec time and calls"""

        key = f"{fct.__module__}.{fct.__name__}"
        r = cls.registry.get(key)

        if (r is None): 
            cls.registry[key] = {}
            cls.registry[key]["calls"] = 0
            cls.registry[key]["runtime"] = 0
            r = cls.registry[key]

        r["calls"] +=1
        r["runtime"] += exec_time

        return None 

    @classmethod
    def event_printer(cls, fct, runtime):
        """print event to console"""

        if not cls.event_prints: 
            return None 
        if cls.print_extra_info:
              extra_info = f"\n     POS_ARG: {args}\n     WK_ARG:{kwargs}\n     RETURN:{r}\n     RUNTIME:{runtime:.4f}s"
        else: extra_info = ""

        return print(f"PROFILER : {fct.__module__}.{fct.__name__}",extra_info) 

    @classmethod
    def wrapper(cls, fct):
        """wrap-profile any functions with our benchmark & counter"""

        #ignore some function?
        if (fct.__name__ in cls.ignore_fcts):
            return fct

        #Blender might check your function.__code__.co_argcount. this make wrapping way more complex
        #https://stackoverflow.com/questions/73601340/how-to-wrap-a-function-with-accurate-code-argcount?noredirect=1#comment129973896_73601340

        #so fct.__code__.co_argcount will be accurate
        if (fct.__defaults__ is not None):
              posonly = fct.__code__.co_argcount - len(fct.__defaults__)
        else: posonly = fct.__code__.co_argcount

        #ignore some function?
        if (fct.__name__ in cls.ignore_fcts):
            return fct

        #debug function? 
        # if (fct.__name__=="_global_to_surface_space"):
        #     print("\n\n","_DEBUG_"*100,"\n\n")
        #     print("_global_to_surface_space")
        #     print("fct.__code__.co_argcount : ",fct.__code__.co_argcount)
        #     print("len(fct.__defaults__) : ",len(fct.__defaults__))
        #     print("posonly : ",posonly)
        #     print("\n\n","_DEBUG_"*100,"\n\n")

        import functools
        import time 

        if (posonly==0):

            @functools.wraps(fct)
            def inner(*args,**kwargs):
                t = time.time()
                r = fct(*args,**kwargs)
                cls.register(fct,runtime exec_time=time= time.time()-t)
                if cls.event_prints:register(fct, exec_time=runtime,)
                    print(f"PROFILER : {fct.__module__}cls.{event_printer(fct.__name__} :, {time.time()-t}"runtime,)
                return r
        
        elif (posonly==1):

            @functools.wraps(fct)
            def inner(a,*args,**kwargs):
                args += (a,)
                t = time.time()
                r = fct(a*args,**kwargs)
                cls.register(fct,runtime exec_time=time= time.time()-t)
                if cls.event_prints:register(fct, exec_time=runtime,)
                    print(f"PROFILER : {fct.__module__}cls.{event_printer(fct.__name__} :, {time.time()-t}"runtime,)
                return r
        
        elif (posonly==2):

            @functools.wraps(fct)
            def inner(a,b,*args,**kwargs):
                args += a,b
                t = time.time()
                r = fct(a,b*args,**kwargs)
                cls.register(fct,runtime exec_time=time= time.time()-t)
                if cls.event_prints:register(fct, exec_time=runtime,)
                    print(f"PROFILER : {fct.__module__}cls.{event_printer(fct.__name__} :, {time.time()-t}"runtime,)
                return r
        
        elif (posonly==3):

            @functools.wraps(fct)
            def inner(a,b,c,*args,**kwargs):
                args += a,b,c
                t = time.time()
                r = fct(a,b,c*args,**kwargs)
                cls.register(fct,runtime exec_time=time= time.time()-t)
                if cls.event_prints:register(fct, exec_time=runtime,)
                    print(f"PROFILER : {fct.__module__}cls.{event_printer(fct.__name__} :, {time.time()-t}"runtime,)
                return r
        
        elif (posonly==4):

            @functools.wraps(fct)
            def inner(a,b,c,d,*args,**kwargs):
                args += a,b,c,d
                t = time.time()
                r = fct(a,b,c,d*args,**kwargs)
                cls.register(fct,runtime exec_time=time= time.time()-t)
                if cls.event_prints:register(fct, exec_time=runtime,)
                    print(f"PROFILER : {fct.__module__}cls.{event_printer(fct.__name__} :, {time.time()-t}"runtime,)
                return r
        
        elif (posonly==5):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,*args,**kwargs):
                args += a,b,c,d,e
                t = time.time()
                r = fct(a,b,c,d,e*args,**kwargs)
                cls.register(fct,runtime exec_time=time= time.time()-t)
                if cls.event_prints:register(fct, exec_time=runtime,)
                    print(f"PROFILER : {fct.__module__}cls.{event_printer(fct.__name__} :, {time.time()-t}"runtime,)
                return r
        
        elif (posonly==6):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,*args,**kwargs):
                args += a,b,c,d,e,f
                t = time.time()
                r = fct(a,b,c,d,e,f*args,**kwargs)
                cls.register(fct,runtime exec_time=time= time.time()-t)
                if cls.event_prints:register(fct, exec_time=runtime,)
                    print(f"PROFILER : {fct.__module__}cls.{event_printer(fct.__name__} :, {time.time()-t}"runtime,)
                return r
        
        elif (posonly==7):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,*args,**kwargs):
                args += a,b,c,d,e,f,g
                t = time.time()
                r = fct(a,b,c,d,e,f,g*args,**kwargs)
                cls.register(fct,runtime exec_time=time= time.time()-t)
                if cls.event_prints:register(fct, exec_time=runtime,)
                    print(f"PROFILER : {fct.__module__}cls.{event_printer(fct.__name__} :, {time.time()-t}"runtime,)
                return r
        
        elif (posonly==8):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,h,*args,**kwargs):
                args += a,b,c,d,e,f,g,h
                t = time.time()
                r = fct(a,b,c,d,e,f,g,h*args,**kwargs)
                cls.register(fct,runtime exec_time=time= time.time()-t)
                if cls.event_prints:register(fct, exec_time=runtime,)
                    print(f"PROFILER : {fct.__module__}cls.{event_printer(fct.__name__} :, {time.time()-t}"runtime,)
                return r
        
        elif (posonly==9):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,h,i,*args,**kwargs):
                args += a,b,c,d,e,f,g,h,i
                t = time.time()
                r = fct(a,b,c,d,e,f,g,h,i*args,**kwargs)
                cls.register(fct,runtime exec_time=time= time.time()-t)
                if cls.event_prints:register(fct, exec_time=runtime,)
                    print(f"PROFILER : {fct.__module__}cls.{event_printer(fct.__name__} :, {time.time()-t}"runtime,)
                return r
        
        elif (posonly==10):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,h,i,j,*args,**kwargs):
                args += a,b,c,d,e,f,g,h,i,j
                t = time.time()
                r = fct(a,b,c,d,e,f,g,h,i,j*args,**kwargs)
                cls.register(fct,runtime exec_time=time= time.time()-t)
                if cls.event_prints:register(fct, exec_time=runtime,)
                    print(f"PROFILER : {fct.__module__}cls.{event_printer(fct.__name__} :, {time.time()-t}"runtime,)
                return r
        
        else:
            raise Exception("PROFILER_ERROR >>> my_wrapper() do not support more than 10 positional argument")

        return inner

    @classmethod
    def start(cls):
        """inject the profiler wrapper for every functions for every modules of our plugin
        used for benchmark or debugging purpose only"""
        
        import sys
        import types

        print("\n","Injecting HomebrewedProfiler"EventProfiler","\n")

        def is_function(obj):
            """check if given object is a function"""
            return isinstance(obj, types.FunctionType)
                
        #for all modules in sys.modules
        for mod_k,mod in sys.modules.copy().items():
            
            #separate module componments names
            mod_list = mod_k.split('.')
            
            #fileter module that isn't ours
            if (mod_list[0]!=cls.plugin_main_module):
                continue
            #ignore main __init__ module
            if ((len(mod_list)==1) and (mod_list[0]==cls.plugin_main_module)):
                continue
            #ignore some modules?
            if any([m in cls.ignore_module for m in mod_list]):
                continue
            
            print("HomebrewedProfiler : Module-Search : ",mod_k)
            
            #for each objects found in module
            for ele_k,ele in mod.__dict__.items():
                
                #if it does not have a name, skip
                if (not hasattr(ele,"__name__")):
                    continue
                
                #we have a global function
                elif is_function(ele):
                    print(f"  - Inject : Local-Fct : {mod_k}.{ele_k}")
                    mod.__dict__[ele_k] = cls.wrapper(ele)

                #then we have a homebrewed class?
                elif repr(ele).startswith(f"<class '{cls.plugin_main_module}."):
                    for class_k,class_e in ele.__dict__.items():
                        if is_function(class_e):
                            print(f"  - Inject : Class-Fct : {mod_k}.{ele_k}.{class_k}")
                            setattr( mod.__dict__[ele_k], class_k, cls.wrapper(class_e),) #class.__dict__ are mapping proxies, need to assign this way
                continue

        print("")

        return None 

    @classmethod
    def end(cls,):
        """calculate averages & optionally print output"""

        print("\n","Generating HomebrewedProfilerEventProfiler Sum","\n")

        for k,v in cls.registry.copy().items():
            cls.registry[k]["averagetime"] = v["runtime"]/v["calls"]

        if cls.outputprint: 

            print("\n","Outputing HomebrewedProfilerEventProfiler Result","\n")

            sorted_registry = dict(sorted(cls.registry.items(), key=lambda item:item[1]["runtime"], reverse=False))

            for k,v in sorted_registry.items():
                print("\n",k,":")
                for a,val in v.items():
                    print(" "*6,a,":",val)

        return None
 

# ooooo                              oooo                                                        .  
# `888'                              `888                                                      .o8  
#  888  ooo. .oo.  .oo.   oo.ooooo.   888   .ooooo.  ooo. .oo.  .oo.    .ooooo.  ooo. .oo.   .o888oo
#  888  `888P"Y88bP"Y88b   888' `88b  888  d88' `88b `888P"Y88bP"Y88b  d88' `88b `888P"Y88b    888  
#  888   888   888   888   888   888  888  888ooo888  888   888   888  888ooo888  888   888    888  
#  888   888   888   888   888   888  888  888    .o  888   888   888  888    .o  888   888    888 .
# o888o o888o o888o o888o  888bod8P' o888o `Y8bod8P' o888o o888o o888o `Y8bod8P' o888o o888o   "888"
#                          888
#                         o888o

#Implementation proposal, in main __init__.register/unregister

 
"""

#####################################
#########Homebrewed Profilerprofiler: ParametersBest ########
#####################################for live prints / debugging

#Homebrewed profiler & options
from . profiler import HomebrewedProfiler
HomebrewedProfiler.plugin_main_module = "Scatter5"
HomebrewedProfiler.event_prints = True #print live execution?
HomebrewedProfiler.outputprint = True #print final stats?
HomebrewedProfiler.ignore_fcts = ["get_psy_active"] #ignore functions usedin ui?
HomebrewedProfiler.ignore_module = ["ui"] #do not profile some sub modules?EventProfiler

#Options

EventProfiler.plugin_main_module = "Scatter5" #filter modules, cannot be ""
EventProfiler.event_prints = True #print live execution?
EventProfiler.print_extra_info = False #print arguments, return values, & execution time of function?
EventProfiler.outputprint = False #print final statistics in console?
EventProfiler.ignore_module = ["ui"] #ignore some modules ? (ui drawing fct?)
EventProfiler.ignore_fcts = [ #ignore some functions (ui drawing fct?)
    "is_compatible_instance",
    "get_psy_active",
    "is_category_used",
    "is_synchronized",
    "is_locked",
    "get_surfaces",
    "get_scatter_mod",
    "translate",
    "cust_icon",
    "get_s_surface_main_features",
    "get_s_distribution_main_features",
    "get_s_mask_main_features",
    "get_s_scale_main_features",
    "get_s_rot_main_features",
    "get_s_pattern_main_features",
    "get_s_abiotic_main_features",
    "get_s_proximity_main_features",
    "get_s_ecosystem_main_features",
    "get_s_push_main_features",
    "get_s_wind_main_features",
    "get_s_instances_main_features",
    "get_s_visibility_main_features",
    "get_s_display_main_features",
    ]

#cProfile profiler: Great for benchmark & optionsfinal statistics with visualizer app

from . profiler import cProfiler
cProfiler.outputprint = False #print final stats?
cProfiler.outputlog = True #write log (will overwrite old log)
cProfiler.runviz = True #try to run vizualisation sofware?
cProfiler.vizapp = "snakeviz" #snakeviz|tuna ? use "pip install x" first

#Choose#Options

cProfiler.outputprint = False #print final stats in console?
cProfiler.outputlog = True #write log needed for viz sofware (will overwrite log with same names)
cProfiler.logname = "my_benchmark" #name of the log file? (path will be located in your profilerlocal typeblender installation, where blender.exe is located)
ChosenProfilercProfiler.runviz = HomebrewedProfilerTrue #run vizualisation sofware? please fit requirements first
cProfiler.vizapp = "snakeviz" #which viz app to call ? snakeviz or  tuna ? -> use "pip install xxx" first

#Turn Profiler on/off here
use_profiler = True 

#####################################
########   Implementation   #########
#####################################

def register():

    #use profiler?
    if use_profiler:
        ChosenProfilercProfiler.start()
        EventProfiler.start()

    for m in main_modules:
        m.register()
    
    return None


def unregister():

    for m in reversed(main_modules):
        m.unregister()

    #final step, remove modules from sys.modules 
    cleanse_modules()

    #output profiler result? 
    if use_profiler:
        ChosenProfilercProfiler.end()
        EventProfiler.end()

    return None


"""
 


#   .oooooo.   ooooooooo.                       .o88o.  o8o  oooo
#  d8P'  `Y8b  `888   `Y88.                     888 `"  `"'  `888
# 888           888   .d88' oooo d8b  .ooooo.  o888oo  oooo   888   .ooooo.
# 888           888ooo88P'  `888""8P d88' `88b  888    `888   888  d88' `88b
# 888           888          888     888   888  888     888   888  888ooo888
# `88b    ooo   888          888     888   888  888     888   888  888    .o
#  `Y8bood8P'  o888o        d888b    `Y8bod8P' o888o   o888o o888o `Y8bod8P'

 

class cProfiler: 

    app = None

    #HomebrewedProfiler Parmeters: 

    #print stats to console?
    outputprint = False 

    #updatelog, will overwrite old log
    outputlog = True 

    #try to run vizualisation sofware?
    runviz = True 

    #snakeviz|tuna ? use "pip install x" first
    vizapp = "snakeviz" 


    @classmethod
    def start(cls):

        import cProfile

        print("\n","Starting cProfiler","\n")
        cls.app = cProfile.Profile()
        cls.app.enable()

        return None

    @classmethod
    def end(cls,):

        if (cls.app is None): 
            return None

        print("\n","Ending cProfiler","\n")

        import pstats
        import io 

        cls.app.disable()
        s = io.StringIO()
        ps = pstats.Stats(cls.app, stream=s).sort_stats(pstats.SortKey.CUMULATIVE)

        if (cls.outputlog or cls.runviz):
            
            import os
            import bpy
                    
            filename = "cprofiler.log"
            localpath = os.path.dirname(bpy.utils.resource_path("LOCAL"))
            path = os.path.join(localpath,filename)

            print("\n",f"cProfiler Dumping Stats : {path}","\n")
            ps.dump_stats(path)

            if cls.runviz:

                import shlex
                import subprocess

                command = f"python -m {cls.vizapp} {filename}"
                print("\n",f"Trying to run {cls.vizapp.title()} : {command}","\n")

                try:
                    #os.system(command)
                    subprocess.Popen(shlex.split(command))
                
                except Exception as e: 

                    print("\n","VizApp failed, did you tried pip install?\nif so please check our source code and see if your OS is properly supported","\n")
        
        if cls.outputprint:

            ps.print_stats()
            print(s.getvalue())

        return None



# ooooo   ooooo                                                                         .o8
# `888'   `888'                                                                        "888
#  888     888   .ooooo.  ooo. .oo.  .oo.    .ooooo.  ooo. .oo.  .oo.    .oooo.    .oooo888   .ooooo.
#  888ooooo888  d88' `88b `888P"Y88bP"Y88b  d88' `88b `888P"Y88bP"Y88b  `P  )88b  d88' `888  d88' `88b
#  888     888  888   888  888   888   888  888ooo888  888   888   888   .oP"888  888   888  888ooo888
#  888     888  888   888  888   888   888  888    .o  888   888   888  d8(  888  888   888  888    .o
# o888o   o888o `Y8bod8P' o888o o888o o888o `Y8bod8P' o888o o888o o888o `Y888""8o `Y8bod88P" `Y8bod8P'

# This version still need more work,
# wrapping is very tricky


class HomebrewedProfiler: 

    #main registry 
    registry = {}

    #HomebrewedProfiler Parmeters: 

    #please define your plugin main module here, it should be the name of your folder
    plugin_main_module = ""

    #print all event?
    event_prints = True

    #end() parameter
    outputprint=True

    #ignore parameters, typically ui functions/modules
    ignore_fcts = []
    ignore_module = []

    @classmethod
    def register(cls, fct, exec_time=0):
        """update internal registry with exec time and calls"""

        key = f"{fct.__module__}.{fct.__name__}"
        r = cls.registry.get(key)

        if (r is None): 
            cls.registry[key] = {}
            cls.registry[key]["calls"] = 0
            cls.registry[key]["runtime"] = 0
            r = cls.registry[key]

        r["calls"] +=1
        r["runtime"] += exec_time

        return None 

    @classmethod
    def wrapper(cls, fct):
        """wrap-profile any functions with our benchmark & counter"""

        #ignore some function?
        if (fct.__name__ in cls.ignore_fcts):
            return fct

        #Blender might check your function.__code__.co_argcount. this make wrapping way more complex
        #https://stackoverflow.com/questions/73601340/how-to-wrap-a-function-with-accurate-code-argcount?noredirect=1#comment129973896_73601340

        #so fct.__code__.co_argcount will be accurate
        if (fct.__defaults__ is not None):
              posonly = fct.__code__.co_argcount - len(fct.__defaults__)
        else: posonly = fct.__code__.co_argcount

        #ignore some function?
        if (fct.__name__ in cls.ignore_fcts):
            return fct

        import functools
        import time 

        if (posonly==0):

            @functools.wraps(fct)
            def inner(**kwargs):
                t = time.time()
                r = fct(**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==1):

            @functools.wraps(fct)
            def inner(a,**kwargs):
                t = time.time()
                r = fct(a,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==2):

            @functools.wraps(fct)
            def inner(a,b,**kwargs):
                t = time.time()
                r = fct(a,b,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==3):

            @functools.wraps(fct)
            def inner(a,b,c,**kwargs):
                t = time.time()
                r = fct(a,b,c,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==4):

            @functools.wraps(fct)
            def inner(a,b,c,d,**kwargs):
                t = time.time()
                r = fct(a,b,c,d,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==5):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,**kwargs):
                t = time.time()
                r = fct(a,b,c,d,e,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==6):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,**kwargs):
                t = time.time()
                r = fct(a,b,c,d,e,f,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==7):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,**kwargs):
                t = time.time()
                r = fct(a,b,c,d,e,f,g,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==8):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,h,**kwargs):
                t = time.time()
                r = fct(a,b,c,d,e,f,g,h,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==9):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,h,i,**kwargs):
                t = time.time()
                r = fct(a,b,c,d,e,f,g,h,i,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==10):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,h,i,j,**kwargs):
                t = time.time()
                r = fct(a,b,c,d,e,f,g,h,i,j,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        else:
            raise Exception("PROFILER_ERROR >>> my_wrapper() do not support more than 10 positional argument")

        return inner

    @classmethod
    def start(cls):
        """inject the profiler wrapper for every functions for every modules of our plugin
        used for benchmark or debugging purpose only"""
        
        import sys
        import types

        print("\n","Injecting HomebrewedProfiler","\n")

        def is_function(obj):
            """check if given object is a function"""
            return isinstance(obj, types.FunctionType)
                
        #for all modules in sys.modules
        for mod_k,mod in sys.modules.copy().items():
            
            #separate module componments names
            mod_list = mod_k.split('.')
            
            #fileter module that isn't ours
            if (mod_list[0]!=cls.plugin_main_module):
                continue
            #ignore main __init__ module
            if ((len(mod_list)==1) and (mod_list[0]==cls.plugin_main_module)):
                continue
            #ignore some modules?
            if any([m in cls.ignore_module for m in mod_list]):
                continue
            
            print("HomebrewedProfiler : Module-Search : ",mod_k)
            
            #for each objects found in module
            for ele_k,ele in mod.__dict__.items():
                
                #if it does not have a name, skip
                if (not hasattr(ele,"__name__")):
                    continue
                
                #we have a global function
                elif is_function(ele):
                    print(f"  - Inject : Local-Fct : {mod_k}.{ele_k}")
                    mod.__dict__[ele_k] = cls.wrapper(ele)

                #then we have a homebrewed class?
                elif repr(ele).startswith(f"<class '{cls.plugin_main_module}."):
                    for class_k,class_e in ele.__dict__.items():
                        if is_function(class_e):
                            print(f"  - Inject : Class-Fct : {mod_k}.{ele_k}.{class_k}")
                            setattr( mod.__dict__[ele_k], class_k, cls.wrapper(class_e),) #class.__dict__ are mapping proxies, need to assign this way
                continue

        print("")

        return None 

    @classmethod
    def end(cls,):
        """calculate averages & optionally print output"""

        print("\n","Generating HomebrewedProfiler Sum","\n")

        for k,v in cls.registry.copy().items():
            cls.registry[k]["averagetime"] = v["runtime"]/v["calls"]

        if cls.outputprint: 

            print("\n","Outputing HomebrewedProfiler Result","\n")

            sorted_registry = dict(sorted(cls.registry.items(), key=lambda item:item[1]["runtime"], reverse=False))

            for k,v in sorted_registry.items():
                print("\n",k,":")
                for a,val in v.items():
                    print(" "*6,a,":",val)

        return None

# ooooo                              oooo                                                        .  
# `888'                              `888                                                      .o8  
#  888  ooo. .oo.  .oo.   oo.ooooo.   888   .ooooo.  ooo. .oo.  .oo.    .ooooo.  ooo. .oo.   .o888oo
#  888  `888P"Y88bP"Y88b   888' `88b  888  d88' `88b `888P"Y88bP"Y88b  d88' `88b `888P"Y88b    888  
#  888   888   888   888   888   888  888  888ooo888  888   888   888  888ooo888  888   888    888  
#  888   888   888   888   888   888  888  888    .o  888   888   888  888    .o  888   888    888 .
# o888o o888o o888o o888o  888bod8P' o888o `Y8bod8P' o888o o888o o888o `Y8bod8P' o888o o888o   "888"
#                          888
#                         o888o

#Implementation proposal, in main __init__.register/unregister

 
"""

#####################################
######## Profiler Parameters ########
#####################################

#Homebrewed profiler & options
from . profiler import HomebrewedProfiler
HomebrewedProfiler.plugin_main_module = "Scatter5"
HomebrewedProfiler.event_prints = True #print live execution?
HomebrewedProfiler.outputprint = True #print final stats?
HomebrewedProfiler.ignore_fcts = ["get_psy_active"] #ignore functions usedin ui?
HomebrewedProfiler.ignore_module = ["ui"] #do not profile some sub modules?

#cProfile profiler & options
from . profiler import cProfiler
cProfiler.outputprint = False #print final stats?
cProfiler.outputlog = True #write log (will overwrite old log)
cProfiler.runviz = True #try to run vizualisation sofware?
cProfiler.vizapp = "snakeviz" #snakeviz|tuna ? use "pip install x" first

#Choose your profiler type
ChosenProfiler = HomebrewedProfiler 

#Turn Profiler on/off here
use_profiler = True 

#####################################
########   Implementation   #########
#####################################

def register():

    #use profiler?
    if use_profiler:
        ChosenProfiler.start()

    for m in main_modules:
        m.register()
    
    return None


def unregister():

    for m in reversed(main_modules):
        m.unregister()

    #final step, remove modules from sys.modules 
    cleanse_modules()

    #output profiler result? 
    if use_profiler:
        ChosenProfiler.end()

    return None


"""

#TODO: cProfile filter plugin modules only?
#TODO: cProfile real time printing maybe?
#TODO: create a plugin out of this 


#   .oooooo.   ooooooooo.                       .o88o.  o8o  oooo
#  d8P'  `Y8b  `888   `Y88.                     888 `"  `"'  `888
# 888           888   .d88' oooo d8b  .ooooo.  o888oo  oooo   888   .ooooo.
# 888           888ooo88P'  `888""8P d88' `88b  888    `888   888  d88' `88b
# 888           888          888     888   888  888     888   888  888ooo888
# `88b    ooo   888          888     888   888  888     888   888  888    .o
#  `Y8bood8P'  o888o        d888b    `Y8bod8P' o888o   o888o o888o `Y8bod8P'


class cProfiler: 

    app = None

    #EventProfiler Parmeters: 

    #print stats to console?
    outputprint = False 

    #updatelog, will overwrite old log
    outputlog = True 

    #log name
    logname = "profile"

    #try to run vizualisation sofware?
    runviz = True 

    #snakeviz|tuna ? use "pip install x" first
    vizapp = "snakeviz" 


    @classmethod
    def start(cls):

        import cProfile

        print("\n","Starting cProfiler","\n")
        cls.app = cProfile.Profile()
        cls.app.enable()

        return None

    @classmethod
    def end(cls,):

        if (cls.app is None): 
            return None

        print("\n","Ending cProfiler","\n")

        import pstats
        import io 

        cls.app.disable()
        s = io.StringIO()
        ps = pstats.Stats(cls.app, stream=s).sort_stats(pstats.SortKey.CUMULATIVE)

        if (cls.outputlog or cls.runviz):
            
            import os
            import bpy
                    
            filename = f"{cls.logname}.log"
            localpath = os.path.dirname(bpy.utils.resource_path("LOCAL"))
            path = os.path.join(localpath,filename)

            print("\n",f"cProfiler Dumping Stats : {path}","\n")
            ps.dump_stats(path)

            if cls.runviz:

                import shlex
                import subprocess

                command = f"python -m {cls.vizapp} {filename}"
                print("\n",f"Trying to run {cls.vizapp.title()} : {command}","\n")

                try:
                    #os.system(command)
                    subprocess.Popen(shlex.split(command))
                
                except Exception as e: 

                    print("\n","VizApp failed, did you tried pip install?\nif so please check our source code and see if your OS is properly supported","\n")
        
        if cls.outputprint:

            ps.print_stats()
            print(s.getvalue())

        return None



# ooooo   ooooo                                                                         .o8
# `888'   `888'                                                                        "888
#  888     888   .ooooo.  ooo. .oo.  .oo.    .ooooo.  ooo. .oo.  .oo.    .oooo.    .oooo888   .ooooo.
#  888ooooo888  d88' `88b `888P"Y88bP"Y88b  d88' `88b `888P"Y88bP"Y88b  `P  )88b  d88' `888  d88' `88b
#  888     888  888   888  888   888   888  888ooo888  888   888   888   .oP"888  888   888  888ooo888
#  888     888  888   888  888   888   888  888    .o  888   888   888  d8(  888  888   888  888    .o
# o888o   o888o `Y8bod8P' o888o o888o o888o `Y8bod8P' o888o o888o o888o `Y888""8o `Y8bod88P" `Y8bod8P'

# This version still need more work,
# wrapping is very tricky


class EventProfiler: 

    #main registry 
    registry = {}

    #EventProfiler Parmeters: 

    #please define your plugin main module here, it should be the name of your folder
    plugin_main_module = ""

    #print all event?
    event_prints = True
    print_extra_info = False

    #end() parameter
    outputprint=True

    #ignore parameters, typically ui functions/modules
    ignore_fcts = []
    ignore_module = []

    @classmethod
    def register(cls, fct, exec_time=0):
        """update internal registry with exec time and calls"""

        key = f"{fct.__module__}.{fct.__name__}"
        r = cls.registry.get(key)

        if (r is None): 
            cls.registry[key] = {}
            cls.registry[key]["calls"] = 0
            cls.registry[key]["runtime"] = 0
            r = cls.registry[key]

        r["calls"] +=1
        r["runtime"] += exec_time

        return None 

    @classmethod
    def event_printer(cls, fct, runtime):
        """print event to console"""

        if not cls.event_prints: 
            return None 
        if cls.print_extra_info:
              extra_info = f"\n     POS_ARG: {args}\n     WK_ARG:{kwargs}\n     RETURN:{r}\n     RUNTIME:{runtime:.4f}s"
        else: extra_info = ""

        return print(f"PROFILER : {fct.__module__}.{fct.__name__}",extra_info) 

    @classmethod
    def wrapper(cls, fct):
        """wrap-profile any functions with our benchmark & counter"""

        #ignore some function?
        if (fct.__name__ in cls.ignore_fcts):
            return fct

        #Blender might check your function.__code__.co_argcount. this make wrapping way more complex
        #https://stackoverflow.com/questions/73601340/how-to-wrap-a-function-with-accurate-code-argcount?noredirect=1#comment129973896_73601340

        #so fct.__code__.co_argcount will be accurate
        if (fct.__defaults__ is not None):
              posonly = fct.__code__.co_argcount - len(fct.__defaults__)
        else: posonly = fct.__code__.co_argcount

        #ignore some function?
        if (fct.__name__ in cls.ignore_fcts):
            return fct

        #debug function? 
        # if (fct.__name__=="_global_to_surface_space"):
        #     print("\n\n","_DEBUG_"*100,"\n\n")
        #     print("_global_to_surface_space")
        #     print("fct.__code__.co_argcount : ",fct.__code__.co_argcount)
        #     print("len(fct.__defaults__) : ",len(fct.__defaults__))
        #     print("posonly : ",posonly)
        #     print("\n\n","_DEBUG_"*100,"\n\n")

        import functools
        import time 

        if (posonly==0):

            @functools.wraps(fct)
            def inner(*args,**kwargs):
                t = time.time()
                r = fct(*args,**kwargs)
                runtime = time.time()-t
                cls.register(fct, exec_time=runtime,)
                cls.event_printer(fct, runtime,)
                return r
        
        elif (posonly==1):

            @functools.wraps(fct)
            def inner(a,*args,**kwargs):
                args += (a,)
                t = time.time()
                r = fct(*args,**kwargs)
                runtime = time.time()-t
                cls.register(fct, exec_time=runtime,)
                cls.event_printer(fct, runtime,)
                return r
        
        elif (posonly==2):

            @functools.wraps(fct)
            def inner(a,b,*args,**kwargs):
                args += a,b
                t = time.time()
                r = fct(*args,**kwargs)
                runtime = time.time()-t
                cls.register(fct, exec_time=runtime,)
                cls.event_printer(fct, runtime,)
                return r
        
        elif (posonly==3):

            @functools.wraps(fct)
            def inner(a,b,c,*args,**kwargs):
                args += a,b,c
                t = time.time()
                r = fct(*args,**kwargs)
                runtime = time.time()-t
                cls.register(fct, exec_time=runtime,)
                cls.event_printer(fct, runtime,)
                return r
        
        elif (posonly==4):

            @functools.wraps(fct)
            def inner(a,b,c,d,*args,**kwargs):
                args += a,b,c,d
                t = time.time()
                r = fct(*args,**kwargs)
                runtime = time.time()-t
                cls.register(fct, exec_time=runtime,)
                cls.event_printer(fct, runtime,)
                return r
        
        elif (posonly==5):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,*args,**kwargs):
                args += a,b,c,d,e
                t = time.time()
                r = fct(*args,**kwargs)
                runtime = time.time()-t
                cls.register(fct, exec_time=runtime,)
                cls.event_printer(fct, runtime,)
                return r
        
        elif (posonly==6):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,*args,**kwargs):
                args += a,b,c,d,e,f
                t = time.time()
                r = fct(*args,**kwargs)
                runtime = time.time()-t
                cls.register(fct, exec_time=runtime,)
                cls.event_printer(fct, runtime,)
                return r
        
        elif (posonly==7):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,*args,**kwargs):
                args += a,b,c,d,e,f,g
                t = time.time()
                r = fct(*args,**kwargs)
                runtime = time.time()-t
                cls.register(fct, exec_time=runtime,)
                cls.event_printer(fct, runtime,)
                return r
        
        elif (posonly==8):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,h,*args,**kwargs):
                args += a,b,c,d,e,f,g,h
                t = time.time()
                r = fct(*args,**kwargs)
                runtime = time.time()-t
                cls.register(fct, exec_time=runtime,)
                cls.event_printer(fct, runtime,)
                return r
        
        elif (posonly==9):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,h,i,*args,**kwargs):
                args += a,b,c,d,e,f,g,h,i
                t = time.time()
                r = fct(*args,**kwargs)
                runtime = time.time()-t
                cls.register(fct, exec_time=runtime,)
                cls.event_printer(fct, runtime,)
                return r
        
        elif (posonly==10):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,h,i,j,*args,**kwargs):
                args += a,b,c,d,e,f,g,h,i,j
                t = time.time()
                r = fct(*args,**kwargs)
                runtime = time.time()-t
                cls.register(fct, exec_time=runtime,)
                cls.event_printer(fct, runtime,)
                return r
        
        else:
            raise Exception("PROFILER_ERROR >>> my_wrapper() do not support more than 10 positional argument")

        return inner

    @classmethod
    def start(cls):
        """inject the profiler wrapper for every functions for every modules of our plugin
        used for benchmark or debugging purpose only"""
        
        import sys
        import types

        print("\n","Injecting EventProfiler","\n")

        def is_function(obj):
            """check if given object is a function"""
            return isinstance(obj, types.FunctionType)
                
        #for all modules in sys.modules
        for mod_k,mod in sys.modules.copy().items():
            
            #separate module componments names
            mod_list = mod_k.split('.')
            
            #fileter module that isn't ours
            if (mod_list[0]!=cls.plugin_main_module):
                continue
            #ignore main __init__ module
            if ((len(mod_list)==1) and (mod_list[0]==cls.plugin_main_module)):
                continue
            #ignore some modules?
            if any([m in cls.ignore_module for m in mod_list]):
                continue
                        
            #for each objects found in module
            for ele_k,ele in mod.__dict__.items():
                
                #if it does not have a name, skip
                if (not hasattr(ele,"__name__")):
                    continue
                
                #we have a global function
                elif is_function(ele):
                    print(f"- Inject : Local-Fct : {mod_k}.{ele_k}")
                    mod.__dict__[ele_k] = cls.wrapper(ele)

                #then we have a homebrewed class?
                elif repr(ele).startswith(f"<class '{cls.plugin_main_module}."):
                    for class_k,class_e in ele.__dict__.items():
                        if is_function(class_e):
                            print(f"- Inject : Class-Fct : {mod_k}.{ele_k}.{class_k}")
                            setattr( mod.__dict__[ele_k], class_k, cls.wrapper(class_e),) #class.__dict__ are mapping proxies, need to assign this way
                continue

        print("")

        return None 

    @classmethod
    def end(cls,):
        """calculate averages & optionally print output"""

        print("\n","Generating EventProfiler Sum","\n")

        for k,v in cls.registry.copy().items():
            cls.registry[k]["averagetime"] = v["runtime"]/v["calls"]

        if cls.outputprint: 

            print("\n","Outputing EventProfiler Result","\n")

            sorted_registry = dict(sorted(cls.registry.items(), key=lambda item:item[1]["runtime"], reverse=False))

            for k,v in sorted_registry.items():
                print("\n",k,":")
                for a,val in v.items():
                    print(" "*6,a,":",val)

        return None
 

# ooooo                              oooo                                                        .  
# `888'                              `888                                                      .o8  
#  888  ooo. .oo.  .oo.   oo.ooooo.   888   .ooooo.  ooo. .oo.  .oo.    .ooooo.  ooo. .oo.   .o888oo
#  888  `888P"Y88bP"Y88b   888' `88b  888  d88' `88b `888P"Y88bP"Y88b  d88' `88b `888P"Y88b    888  
#  888   888   888   888   888   888  888  888ooo888  888   888   888  888ooo888  888   888    888  
#  888   888   888   888   888   888  888  888    .o  888   888   888  888    .o  888   888    888 .
# o888o o888o o888o o888o  888bod8P' o888o `Y8bod8P' o888o o888o o888o `Y8bod8P' o888o o888o   "888"
#                          888
#                         o888o

#Implementation proposal, in main __init__.register/unregister

"""

#Homebrewed profiler: Best for live prints / debugging

from . profiler import EventProfiler

#Options

EventProfiler.plugin_main_module = "Scatter5" #filter modules, cannot be ""
EventProfiler.event_prints = True #print live execution?
EventProfiler.print_extra_info = False #print arguments, return values, & execution time of function?
EventProfiler.outputprint = False #print final statistics in console?
EventProfiler.ignore_module = ["ui"] #ignore some modules ? (ui drawing fct?)
EventProfiler.ignore_fcts = [ #ignore some functions (ui drawing fct?)
    "is_compatible_instance",
    "get_psy_active",
    "is_category_used",
    "is_synchronized",
    "is_locked",
    "get_surfaces",
    "get_scatter_mod",
    "translate",
    "cust_icon",
    "get_s_surface_main_features",
    "get_s_distribution_main_features",
    "get_s_mask_main_features",
    "get_s_scale_main_features",
    "get_s_rot_main_features",
    "get_s_pattern_main_features",
    "get_s_abiotic_main_features",
    "get_s_proximity_main_features",
    "get_s_ecosystem_main_features",
    "get_s_push_main_features",
    "get_s_wind_main_features",
    "get_s_instances_main_features",
    "get_s_visibility_main_features",
    "get_s_display_main_features",
    ]

#cProfile profiler: Great for benchmark & final statistics with visualizer app

from . profiler import cProfiler

#Options

cProfiler.outputprint = False #print final stats in console?
cProfiler.outputlog = True #write log needed for viz sofware (will overwrite log with same names)
cProfiler.logname = "my_benchmark" #name of the log file? (path will be located in your local blender installation, where blender.exe is located)
cProfiler.runviz = True #run vizualisation sofware? please fit requirements first
cProfiler.vizapp = "snakeviz" #which viz app to call ? snakeviz or  tuna ? -> use "pip install xxx" first

#Turn Profiler on/off here
use_profiler = True 



def register():

    if use_profiler:
        cProfiler.start()
        EventProfiler.start()

    for m in main_modules:
        m.register()
    
    return None


def unregister():

    for m in reversed(main_modules):
        m.unregister()

    if use_profiler:
        cProfiler.end()
        EventProfiler.end()

    return None


"""
 
added 45 characters in body
Source Link
Fox
  • 2.1k
  • 22
  • 49
  • 1: create your own profiler, this can be done, in theory, by procedurally injecting a wrapper on every functions found on your plugin modules (quite tricky as blender will check for functions positional arguments)

  • 2: use the cProfilecProfile module. It has the advantage of being natively integrated in CPythonPython, therefore the implementation is done on a much lower level. the cProfiledata can then be exporteddumped & imported in visualization softwareapps such as tunatuna or snakevissnakeviz ( use pip install snakeviz first of course)

Find hereby two implementation of profilers, class with an implementation proposal/example

  • 1: create your own profiler, this can be done, in theory, by procedurally injecting a wrapper on every functions found on your plugin modules

  • 2: use the cProfile module. It has the advantage of being natively integrated in CPython, therefore the implementation is done on a much lower level. the cProfile can then be exported in visualization software such as tuna or snakevis ( use pip install snakeviz first)

Find hereby two implementation of profilers, with implementation proposal

  • 1: create your own profiler, this can be done, in theory, by procedurally injecting a wrapper on every functions found on your plugin modules (quite tricky as blender will check for functions positional arguments)

  • 2: use the cProfile module. It has the advantage of being natively integrated in Python, therefore the implementation is done on a much lower level. the data can then be dumped & imported in visualization apps such as tuna or snakeviz ( use pip install first of course)

Find hereby two profilers class with an implementation proposal/example

added 2604 characters in body
Source Link
Fox
  • 2.1k
  • 22
  • 49

I found two potential ways of implementing a profiler in a blender plugin:

  • 1: create your own profiler, this can be done, in theory, by procedurally injecting a wrapper on every functions found on your plugin modules

  • 2: use the cProfile module. It has the advantage of being natively integrated in CPython, therefore the implementation is done on a much lower level. the cProfile can then be exported in visualization software such as tuna or snakevis ( use pip install snakeviz first)

Find hereby two implementation of profilers, with implementation proposal

# ooooooooo.                       .o88o.  o8o  oooo
# `888   `Y88.                     888 `"  `"'  `888
#  888   .d88' oooo d8b  .ooooo.  o888oo  oooo   888   .ooooo.  oooo d8b
#  888ooo88P'  `888""8P d88' `88b  888    `888   888  d88' `88b `888""8P
#  888          888     888   888  888     888   888  888ooo888  888
#  888          888     888   888  888     888   888  888    .o  888
# o888o        d888b    `Y8bod8P' o888o   o888o o888o `Y8bod8P' d888b

#   .oooooo.   ooooooooo.                       .o88o.  o8o  oooo
#  d8P'  `Y8b  `888   `Y88.                     888 `"  `"'  `888
# 888           888   .d88' oooo d8b  .ooooo.  o888oo  oooo   888   .ooooo.
# 888           888ooo88P'  `888""8P d88' `88b  888    `888   888  d88' `88b
# 888           888          888     888   888  888     888   888  888ooo888
# `88b    ooo   888          888     888   888  888     888   888  888    .o
#  `Y8bood8P'  o888o        d888b    `Y8bod8P' o888o   o888o o888o `Y8bod8P'

"""
### How to use:

    - Please define `plugin_main_module` once, here below.
    - add `Profiler.inject()` in main `__init__.register()`
    - you can print the result with `Profiler.print_registry()`
      we advise that you add this line in main `__init__.unregister()`
    - you can ignore some functions or modules by defining `ignore_fcts` or `ignore_module`

    -class ExamplecProfiler: 

        from . profilerapp import= ProfilerNone

        def#HomebrewedProfiler register()Parmeters: 

            Profiler.allow#print =stats Trueto console?
            Profiler.event_printsoutputprint = True
           False Profiler.inject()

           #updatelog, forwill moverwrite inold main_modules:log
             outputlog = True m.register()

    #try to run vizualisation defsofware?
 unregister():   runviz = True 

         #snakeviz|tuna ? use for"pip minstall inx" reversed(main_modules):first
             vizapp = "snakeviz" m.unregister()

            if Profiler.activated:
                Profiler.print_registry()

        @classmethod
    returndef Nonestart(cls):

### How it works:     import cProfile

    - the profiler will searchprint("\n","Starting forcProfiler","\n")
 functions in every modules and inject the `profile_wrap`cls.app function= cProfile.Profile()
    
### Known issue:  cls.app.enable()

    - if you are using keyword as standard arguments the profiler may crash
      ex: def hello(a,b,c): pass ;return hello(a=1,b=2,c=3)None

"""    @classmethod
    def end(cls,):

class Profiler       if (cls.app is None): 
            return None

    #is profiler is running?
    allow = False
    activated =print("\n","Ending FalsecProfiler","\n")

    #please define your plugin main module here, it should beimport thepstats
 name of your folder
    plugin_main_moduleimport =io "Scatter5"

    #main registry   cls.app.disable()
    registry    s = {}io.StringIO()
        ps = pstats.Stats(cls.app, stream=s).sort_stats(pstats.SortKey.CUMULATIVE)

    #ignore parameters, typically ui functions/modules
    ignore_fcts = [
        "is_compatible_instance",
        "get_psy_active",
        "is_category_used",
        "is_synchronized",
        "is_locked",
        "get_surfaces",
        "get_scatter_mod",
        "translate",
        "cust_icon",
     if (cls.outputlog or "get_s_surface_main_features",cls.runviz):
        "get_s_distribution_main_features",
        "get_s_mask_main_features",
        "get_s_scale_main_features",
       import "get_s_rot_main_features",os
        "get_s_pattern_main_features",
       import "get_s_abiotic_main_features",bpy
        "get_s_proximity_main_features",
        "get_s_ecosystem_main_features",
        "get_s_push_main_features",
        "get_s_wind_main_features",
      filename = "get_s_instances_main_features","cprofiler.log"
        "get_s_visibility_main_features",
      localpath = "get_s_display_main_features",os.path.dirname(bpy.utils.resource_path("LOCAL"))
        ]
    ignore_modulepath = [
        "ui"os.path.join(localpath,
        ]filename)

            print("\n",f"cProfiler Dumping Stats : {path}","\n")
            ps.dump_stats(path)

    event_prints = True #print all event?   if cls.runviz:

    @classmethod            import shlex
    def print_registry(cls):           import subprocess

        #generate total
       command for= k,vf"python in-m {cls.registry.copy().items():vizapp} {filename}"
                print("\n",f"Trying to run {cls.registry[k]["averagetime"]vizapp.title()} =: v["runtime"]/v["calls"]{command}","\n")

        print        try:
                    #os.system(""command)
        print("PROFILER: PRINTING OUTCOME"          subprocess.Popen(shlex.split(command))
                
                except Exception as e: 

        sorted_registry = dict(sorted(cls.registry.items          print()"\n", key=lambda"VizApp item:item[1]["runtime"]failed, reverse=False)did you tried pip install?\nif so please check our source code and see if your OS is properly supported","\n")
        
        if cls.outputprint:

        for k,v in sorted_registry ps.itemsprint_stats():
            print("\n",k,":")
            for a,val in vs.itemsgetvalue():
                print(" "*6,a,":",val)

        return None



# ooooo   ooooo                                                                         .o8
# `888'   `888'                                                                        "888
#  888     888   .ooooo.  ooo. .oo.  .oo.    .ooooo.  ooo. .oo.  .oo.    .oooo.    .oooo888   .ooooo.
#  888ooooo888  d88' `88b `888P"Y88bP"Y88b  d88' `88b `888P"Y88bP"Y88b  `P  )88b  d88' `888  d88' `88b
#  888     888  888   888  888   888   888  888ooo888  888   888   888   .oP"888  888   888  888ooo888
#  888     888  888   888  888   888   888  888    .o  888   888   888  d8(  888  888   888  888    .o
# o888o   o888o `Y8bod8P' o888o o888o o888o `Y8bod8P' o888o o888o o888o `Y888""8o `Y8bod88P" `Y8bod8P'

# This version still need more work,
# wrapping is very tricky


class HomebrewedProfiler: 

    #main registry 
    registry = {}

    #HomebrewedProfiler Parmeters: 

    #please define your plugin main module here, it should be the name of your folder
    plugin_main_module = ""

    #print all event?
    event_prints = True

    #end() parameter
    outputprint=True

    #ignore parameters, typically ui functions/modules
    ignore_fcts = []
    ignore_module = []

    @classmethod
    def update_registryregister(cls, fct, exec_time=0):
        """update internal registry with exec time and calls"""

        key = f"{fct.__module__}.{fct.__name__}"
        r = cls.registry.get(key)

        if (r is None): 
            cls.registry[key] = {}
            cls.registry[key]["calls"] = 0
            cls.registry[key]["runtime"] = 0
            r = cls.registry[key]

        r["calls"] +=1
        r["runtime"] += exec_time

        return None 

    @classmethod
    def profile_wrapwrapper(cls, fct):
        """wrap-profile any functions with our benchmark & counter"""

        #ignore some function?
        if (fct.__name__ in cls.ignore_fcts):
            return fct

        import functools
        import time 

        #Blender might check your function.__code__.co_argcount. sothis wemake neededwrapping toway havemore complex
        #https://stackoverflow.com/questions/73601340/how-to-wrap-a-function-with-accurate-code-argcount?noredirect=1#comment129973896_73601340
        #find back the positional arguments count
        #so fct.__code__.co_argcount will be accurate

        #so fct.__code__.co_argcount will be accurate
        if (fct.__defaults__ is not None):
              force_argposonly = fct.__code__.co_argcount - len(fct.__defaults__)
        else: force_argposonly = fct.__code__.co_argcount

        #injection debugging:
        if (fct.__name__=="_global_to_surface_space"):
            print("")
            print(f"  INJECTION_DEBUG : {fct.__name__}()")
            print(f"     positional_arguments: -> ",force_arg )
            print(f"     kw_arguments:         -> ",len(fct.__defaults__) )
            print(f"     total_arguments:      -> ",fct.__code__.co_argcount )
            print("")

        try: 

            if (force_arg==0):
                    
                @functools.wraps(fct)
                def inner(**kwargs):
                    t = time.time()
                    r = fct(**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                    return r

            elif (force_arg==1):

                @functools.wraps(fct)
                def inner(a,**kwargs):
                    t = time.time()
                    r = fct(a,**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                    return r

            elif (force_arg==2):

                @functools.wraps(fct)
                def inner(a,b,**kwargs):
                    t = time.time()
                    r = fct(a,b,**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                    return r

            elif (force_arg==3):

                @functools.wraps(fct)
                def inner(a,b,c,**kwargs):
                    t = time.time()
                    r = fct(a,b,c,**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                    return r

            elif (force_arg==4):

                @functools.wraps(fct)
                def inner(a,b,c,d,**kwargs):
                    t = time.time()
                    r = fct(a,b,c,d,**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                    return r

            elif (force_arg==5):

                @functools.wraps(fct)
                def inner(a,b,c,d,e,**kwargs):
                    t = time.time()
                    r = fct(a,b,c,d,e,**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                    return r

        #ignore some function?
    elif    if (force_arg==6fct.__name__ in cls.ignore_fcts):
            return fct

                @functools.wraps(fct)
                def inner(a,b,c,d,e,f,**kwargs):
                    t = time.time()
                    r = fct(a,b,c,d,e,f,**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints:import functools
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} :import {time.time()-t}")
                    return r

            elifif (force_arg==7posonly==0):

                @functools.wraps(fct)
                def inner(a,b,c,d,e,f,g,**kwargs):
                    t = time.time()
                    r = fct(a,b,c,d,e,f,g,**kwargs)
                    cls.update_registryregister(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
   return r    
        elif (posonly==1):

            @functools.wraps(fct)
            def inner(a,**kwargs):
                t = time.time()
                r = fct(a,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (force_arg==8posonly==2):

                @functools.wraps(fct)
                def inner(a,b,c,d,e,f,g,h,**kwargs):
                    t = time.time()
                    r = fct(a,b,c,d,e,f,g,h,**kwargs)
                    cls.update_registryregister(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
   return r    
        elif (posonly==3):

            @functools.wraps(fct)
            def inner(a,b,c,**kwargs):
                t = time.time()
                r = fct(a,b,c,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (force_arg==9posonly==4):

                @functools.wraps(fct)
                def inner(a,b,c,d,e,f,g,h,i,**kwargs):
                    t = time.time()
                    r = fct(a,b,c,d,e,f,g,h,i,**kwargs)
                    cls.update_registryregister(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
   return r    
        elif (posonly==5):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,**kwargs):
                t = time.time()
                r = fct(a,b,c,d,e,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (force_arg==10posonly==6):

                @functools.wraps(fct)
                def inner(a,b,c,d,e,f,g,h,i,j,**kwargs):
                    t = time.time()
                    r = fct(a,b,c,d,e,f,g,h,i,j,**kwargs)
                    cls.update_registryregister(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
   return r    
        elif (posonly==7):

            else@functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,**kwargs): 
 raise Exception              t = time.time("PROFILER_ERROR)
 >>> my_wrapper              r = fct(a,b,c,d,e,f,g,**kwargs) 
 do not support more than 10 positional argument"        cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==8):

        except Exception as  @functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,h,**kwargs):
                t = time.time()
                r = fct(a,b,c,d,e,f,g,h,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==9):

            print@functools.wraps(""fct)
            printdef inner("PROFILER_ERRORa,b,c,d,e,f,g,h,i,**kwargs):
 >>> An error occured :"           t = time.time()
            print    r = fct(a,b,c,d,e,f,g,h,i,**kwargs)
            print    cls.register("PROFILER_ERRORfct, >>>exec_time=time.time()-t)
 We used a fallback solution, it might cause issues with high order functions   if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
            print    return r
        
        elif (""posonly==10):

            @functools.wraps(fct)
            def inner(*argsa,b,c,d,e,f,g,h,i,j,**kwargs):
                t = time.time()
                r = fct(*argsa,b,c,d,e,f,g,h,i,j,**kwargs)
                cls.update_registryregister(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        else:
            raise Exception("PROFILER_ERROR >>> my_wrapper() do not support more than 10 positional argument")

        return inner

    @classmethod
    def injectstart(cls):
        """inject the profiler wrapper for every functions for every modules of our plugin
        used for benchmark or debugging purpose only"""
            
        if (not cls.allow):
            return None 
        cls.activated = True 
        
        import types
        import sys
        import types

        print("\n","Injecting HomebrewedProfiler","\n")

        def is_function(obj):
            """check if given object is a function"""
            return isinstance(obj, types.FunctionType)
                
        print("")

        #for all modules in sys.modules
        for mod_k,mod in sys.modules.copy().items():
            
            #separate module componments names
            mod_list = mod_k.split('.')
            
            #fileter whatmodule that isn't ours
            if (mod_list[0]!=cls.plugin_main_module):
                continue
            #ignore main __init__ module
            if ((len(mod_list)==1) and (mod_list[0]==cls.plugin_main_module)):
                continue
            #ignore some modules?
            if any([m in cls.ignore_module for m in mod_list]):
                continue
            
            print("PROFILER_SEARCH"HomebrewedProfiler : Module-Search : ",mod_k)
            
            #for each objects found in module
            for ele_k,ele in mod.__dict__.items():
                
                #if it does not have a name, skip
                if (not hasattr(ele,"__name__")):
                    continue
                
                #we have a global function
                elif is_function(ele):
                    #printprint(f"  INJECT- LOCAL_FUNCTIONInject : Local-Fct : {mod_k}.{ele_k}")
                    mod.__dict__[ele_k] = cls.profile_wrapwrapper(ele)

                #then we have a homebrewed class? search for class.fcts (this class functions support is perhaps a but buggy)
                elif repr(ele).startswith(f"<class '{cls.plugin_main_module}."):
                    for class_k,class_e in ele.__dict__.items():
                        if is_function(class_e):
                            #printprint(f"  INJECT- CLASS_FUNCTIONInject : Class-Fct : {mod_k}.{ele_k}.{class_k}")
                            setattr( mod.__dict__[ele_k], class_k, cls.profile_wrapwrapper(class_e),) #class.__dict__ are mapping proxies, need to assign this way,
                continue

        print("")

        return None 

    @classmethod
    def end(cls,):
        """calculate averages & optionally print output"""

        print("\n","Generating HomebrewedProfiler Sum","\n")

        for k,v in cls.registry.copy().items():
            cls.registry[k]["averagetime"] = v["runtime"]/v["calls"]

        if cls.outputprint: 

            print("\n","Outputing HomebrewedProfiler Result","\n")

            sorted_registry = dict(sorted(cls.registry.items(), key=lambda item:item[1]["runtime"], reverse=False))

            for k,v in sorted_registry.items():
                print("\n",k,":")
                for a,val in v.items():
                    print(" "*6,a,":",val)

        return None

# ooooo                              oooo                                                        .  
# `888'                              `888                                                      .o8  
#  888  ooo. .oo.  .oo.   oo.ooooo.   888   .ooooo.  ooo. .oo.  .oo.    .ooooo.  ooo. .oo.   .o888oo
#  888  `888P"Y88bP"Y88b   888' `88b  888  d88' `88b `888P"Y88bP"Y88b  d88' `88b `888P"Y88b    888  
#  888   888   888   888   888   888  888  888ooo888  888   888   888  888ooo888  888   888    888  
#  888   888   888   888   888   888  888  888    .o  888   888   888  888    .o  888   888    888 .
# o888o o888o o888o o888o  888bod8P' o888o `Y8bod8P' o888o o888o o888o `Y8bod8P' o888o o888o   "888"
#                          888
#                         o888o

#Implementation proposal, in main __init__.register/unregister


"""

#####################################
######## Profiler Parameters ########
#####################################

#Homebrewed profiler & options
from . profiler import HomebrewedProfiler
HomebrewedProfiler.plugin_main_module = "Scatter5"
HomebrewedProfiler.event_prints = True #print live execution?
HomebrewedProfiler.outputprint = True #print final stats?
HomebrewedProfiler.ignore_fcts = ["get_psy_active"] #ignore functions usedin ui?
HomebrewedProfiler.ignore_module = ["ui"] #do not profile some sub modules?

#cProfile profiler & options
from . profiler import cProfiler
cProfiler.outputprint = False #print final stats?
cProfiler.outputlog = True #write log (will overwrite old log)
cProfiler.runviz = True #try to run vizualisation sofware?
cProfiler.vizapp = "snakeviz" #snakeviz|tuna ? use "pip install x" first

#Choose your profiler type
ChosenProfiler = HomebrewedProfiler 

#Turn Profiler on/off here
use_profiler = True 

#####################################
########   Implementation   #########
#####################################

def register():

    #use profiler?
    if use_profiler:
        ChosenProfiler.start()

    for m in main_modules:
        m.register()
    
    return None


def unregister():

    for m in reversed(main_modules):
        m.unregister()

    #final step, remove modules from sys.modules 
    cleanse_modules()

    #output profiler result? 
    if use_profiler:
        ChosenProfiler.end()

    return None


"""
# ooooooooo.                       .o88o.  o8o  oooo
# `888   `Y88.                     888 `"  `"'  `888
#  888   .d88' oooo d8b  .ooooo.  o888oo  oooo   888   .ooooo.  oooo d8b
#  888ooo88P'  `888""8P d88' `88b  888    `888   888  d88' `88b `888""8P
#  888          888     888   888  888     888   888  888ooo888  888
#  888          888     888   888  888     888   888  888    .o  888
# o888o        d888b    `Y8bod8P' o888o   o888o o888o `Y8bod8P' d888b


"""
### How to use:

    - Please define `plugin_main_module` once, here below.
    - add `Profiler.inject()` in main `__init__.register()`
    - you can print the result with `Profiler.print_registry()`
      we advise that you add this line in main `__init__.unregister()`
    - you can ignore some functions or modules by defining `ignore_fcts` or `ignore_module`

    - Example: 

        from . profiler import Profiler

        def register():

            Profiler.allow = True 
            Profiler.event_prints = True
            Profiler.inject()

            for m in main_modules:
                m.register()

        def unregister():

            for m in reversed(main_modules):
                m.unregister()

            if Profiler.activated:
                Profiler.print_registry()

            return None

### How it works:

    - the profiler will search for functions in every modules and inject the `profile_wrap` function
    
### Known issue: 

    - if you are using keyword as standard arguments the profiler may crash
      ex: def hello(a,b,c): pass ; hello(a=1,b=2,c=3)

"""

class Profiler: 

    #is profiler is running?
    allow = False
    activated = False

    #please define your plugin main module here, it should be the name of your folder
    plugin_main_module = "Scatter5"

    #main registry 
    registry = {}

    #ignore parameters, typically ui functions/modules
    ignore_fcts = [
        "is_compatible_instance",
        "get_psy_active",
        "is_category_used",
        "is_synchronized",
        "is_locked",
        "get_surfaces",
        "get_scatter_mod",
        "translate",
        "cust_icon",
        "get_s_surface_main_features",
        "get_s_distribution_main_features",
        "get_s_mask_main_features",
        "get_s_scale_main_features",
        "get_s_rot_main_features",
        "get_s_pattern_main_features",
        "get_s_abiotic_main_features",
        "get_s_proximity_main_features",
        "get_s_ecosystem_main_features",
        "get_s_push_main_features",
        "get_s_wind_main_features",
        "get_s_instances_main_features",
        "get_s_visibility_main_features",
        "get_s_display_main_features",
        ]
    ignore_module = [
        "ui",
        ]


    event_prints = True #print all event?

    @classmethod
    def print_registry(cls): 

        #generate total
        for k,v in cls.registry.copy().items():
            cls.registry[k]["averagetime"] = v["runtime"]/v["calls"]

        print("")
        print("PROFILER: PRINTING OUTCOME")

        sorted_registry = dict(sorted(cls.registry.items(), key=lambda item:item[1]["runtime"], reverse=False))

        for k,v in sorted_registry.items():
            print("\n",k,":")
            for a,val in v.items():
                print(" "*6,a,":",val)

        return None

    @classmethod
    def update_registry(cls, fct, exec_time=0):

        key = f"{fct.__module__}.{fct.__name__}"
        r = cls.registry.get(key)

        if (r is None): 
            cls.registry[key] = {}
            cls.registry[key]["calls"] = 0
            cls.registry[key]["runtime"] = 0
            r = cls.registry[key]

        r["calls"] +=1
        r["runtime"] += exec_time

        return None 

    @classmethod
    def profile_wrap(cls, fct):
        """wrap-profile any functions with our benchmark & counter"""

        #ignore some function?
        if (fct.__name__ in cls.ignore_fcts):
            return fct

        import functools
        import time 

        #Blender might check your function.__code__.co_argcount so we needed to have 
        #https://stackoverflow.com/questions/73601340/how-to-wrap-a-function-with-accurate-code-argcount?noredirect=1#comment129973896_73601340
        #find back the positional arguments count
        #so fct.__code__.co_argcount will be accurate

        if (fct.__defaults__ is not None):
              force_arg = fct.__code__.co_argcount - len(fct.__defaults__)
        else: force_arg = fct.__code__.co_argcount

        #injection debugging:
        if (fct.__name__=="_global_to_surface_space"):
            print("")
            print(f"  INJECTION_DEBUG : {fct.__name__}()")
            print(f"     positional_arguments: -> ",force_arg )
            print(f"     kw_arguments:         -> ",len(fct.__defaults__) )
            print(f"     total_arguments:      -> ",fct.__code__.co_argcount )
            print("")

        try: 

            if (force_arg==0):
                    
                @functools.wraps(fct)
                def inner(**kwargs):
                    t = time.time()
                    r = fct(**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                    return r

            elif (force_arg==1):

                @functools.wraps(fct)
                def inner(a,**kwargs):
                    t = time.time()
                    r = fct(a,**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                    return r

            elif (force_arg==2):

                @functools.wraps(fct)
                def inner(a,b,**kwargs):
                    t = time.time()
                    r = fct(a,b,**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                    return r

            elif (force_arg==3):

                @functools.wraps(fct)
                def inner(a,b,c,**kwargs):
                    t = time.time()
                    r = fct(a,b,c,**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                    return r

            elif (force_arg==4):

                @functools.wraps(fct)
                def inner(a,b,c,d,**kwargs):
                    t = time.time()
                    r = fct(a,b,c,d,**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                    return r

            elif (force_arg==5):

                @functools.wraps(fct)
                def inner(a,b,c,d,e,**kwargs):
                    t = time.time()
                    r = fct(a,b,c,d,e,**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                    return r

            elif (force_arg==6):

                @functools.wraps(fct)
                def inner(a,b,c,d,e,f,**kwargs):
                    t = time.time()
                    r = fct(a,b,c,d,e,f,**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                    return r

            elif (force_arg==7):

                @functools.wraps(fct)
                def inner(a,b,c,d,e,f,g,**kwargs):
                    t = time.time()
                    r = fct(a,b,c,d,e,f,g,**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                    return r

            elif (force_arg==8):

                @functools.wraps(fct)
                def inner(a,b,c,d,e,f,g,h,**kwargs):
                    t = time.time()
                    r = fct(a,b,c,d,e,f,g,h,**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                    return r

            elif (force_arg==9):

                @functools.wraps(fct)
                def inner(a,b,c,d,e,f,g,h,i,**kwargs):
                    t = time.time()
                    r = fct(a,b,c,d,e,f,g,h,i,**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                    return r

            elif (force_arg==10):

                @functools.wraps(fct)
                def inner(a,b,c,d,e,f,g,h,i,j,**kwargs):
                    t = time.time()
                    r = fct(a,b,c,d,e,f,g,h,i,j,**kwargs)
                    cls.update_registry(fct, exec_time=time.time()-t)
                    if cls.event_prints: 
                        print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                    return r

            else: raise Exception("PROFILER_ERROR >>> my_wrapper() do not support more than 10 positional argument")

        except Exception as e:

            print("")
            print("PROFILER_ERROR >>> An error occured :")
            print(e)
            print("PROFILER_ERROR >>> We used a fallback solution, it might cause issues with high order functions...")
            print("")

            @functools.wraps(fct)
            def inner(*args,**kwargs):
                t = time.time()
                r = fct(*args,**kwargs)
                cls.update_registry(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r

        return inner

    @classmethod
    def inject(cls):
        """inject the profiler wrapper for every functions for every modules of our plugin
        used for benchmark or debugging purpose only"""
            
        if (not cls.allow):
            return None 
        cls.activated = True 
        
        import types
        import sys

        def is_function(obj):
            """check if given object is a function"""
            return isinstance(obj, types.FunctionType)
                
        print("")

        #for all modules in sys.modules
        for mod_k,mod in sys.modules.copy().items():
            
            #separate module componments names
            mod_list = mod_k.split('.')
            
            #fileter what isn't ours
            if (mod_list[0]!=cls.plugin_main_module):
                continue

            #ignore some modules?
            if any([m in cls.ignore_module for m in mod_list]):
                continue
            
            print("PROFILER_SEARCH : ",mod_k)
            
            #for each objects found in module
            for ele_k,ele in mod.__dict__.items():
                
                #if it does not have a name, skip
                if (not hasattr(ele,"__name__")):
                    continue
                
                #we have a global function
                elif is_function(ele):
                    #print(f"  INJECT LOCAL_FUNCTION: {mod_k}.{ele_k}")
                    mod.__dict__[ele_k] = cls.profile_wrap(ele)

                #then we have a homebrewed class? search for class.fcts (this class functions support is perhaps a but buggy)
                elif repr(ele).startswith(f"<class '{cls.plugin_main_module}."):
                    for class_k,class_e in ele.__dict__.items():
                        if is_function(class_e):
                            #print(f"  INJECT CLASS_FUNCTION: {mod_k}.{ele_k}.{class_k}")
                            setattr( mod.__dict__[ele_k], class_k, cls.profile_wrap(class_e),) #class.__dict__ are mapping proxies, need to assign this way,
                continue

        print("")

        return None 

I found two potential ways of implementing a profiler in a blender plugin:

  • 1: create your own profiler, this can be done, in theory, by procedurally injecting a wrapper on every functions found on your plugin modules

  • 2: use the cProfile module. It has the advantage of being natively integrated in CPython, therefore the implementation is done on a much lower level. the cProfile can then be exported in visualization software such as tuna or snakevis ( use pip install snakeviz first)

Find hereby two implementation of profilers, with implementation proposal



#   .oooooo.   ooooooooo.                       .o88o.  o8o  oooo
#  d8P'  `Y8b  `888   `Y88.                     888 `"  `"'  `888
# 888           888   .d88' oooo d8b  .ooooo.  o888oo  oooo   888   .ooooo.
# 888           888ooo88P'  `888""8P d88' `88b  888    `888   888  d88' `88b
# 888           888          888     888   888  888     888   888  888ooo888
# `88b    ooo   888          888     888   888  888     888   888  888    .o
#  `Y8bood8P'  o888o        d888b    `Y8bod8P' o888o   o888o o888o `Y8bod8P'



class cProfiler: 

    app = None

    #HomebrewedProfiler Parmeters: 

    #print stats to console?
    outputprint = False 

    #updatelog, will overwrite old log
    outputlog = True 

    #try to run vizualisation sofware?
    runviz = True 

    #snakeviz|tuna ? use "pip install x" first
    vizapp = "snakeviz" 


    @classmethod
    def start(cls):

        import cProfile

        print("\n","Starting cProfiler","\n")
        cls.app = cProfile.Profile()
        cls.app.enable()

        return None

    @classmethod
    def end(cls,):

        if (cls.app is None): 
            return None

        print("\n","Ending cProfiler","\n")

        import pstats
        import io 

        cls.app.disable()
        s = io.StringIO()
        ps = pstats.Stats(cls.app, stream=s).sort_stats(pstats.SortKey.CUMULATIVE)

        if (cls.outputlog or cls.runviz):
            
            import os
            import bpy
                    
            filename = "cprofiler.log"
            localpath = os.path.dirname(bpy.utils.resource_path("LOCAL"))
            path = os.path.join(localpath,filename)

            print("\n",f"cProfiler Dumping Stats : {path}","\n")
            ps.dump_stats(path)

            if cls.runviz:

                import shlex
                import subprocess

                command = f"python -m {cls.vizapp} {filename}"
                print("\n",f"Trying to run {cls.vizapp.title()} : {command}","\n")

                try:
                    #os.system(command)
                    subprocess.Popen(shlex.split(command))
                
                except Exception as e: 

                    print("\n","VizApp failed, did you tried pip install?\nif so please check our source code and see if your OS is properly supported","\n")
        
        if cls.outputprint:

            ps.print_stats()
            print(s.getvalue())

        return None



# ooooo   ooooo                                                                         .o8
# `888'   `888'                                                                        "888
#  888     888   .ooooo.  ooo. .oo.  .oo.    .ooooo.  ooo. .oo.  .oo.    .oooo.    .oooo888   .ooooo.
#  888ooooo888  d88' `88b `888P"Y88bP"Y88b  d88' `88b `888P"Y88bP"Y88b  `P  )88b  d88' `888  d88' `88b
#  888     888  888   888  888   888   888  888ooo888  888   888   888   .oP"888  888   888  888ooo888
#  888     888  888   888  888   888   888  888    .o  888   888   888  d8(  888  888   888  888    .o
# o888o   o888o `Y8bod8P' o888o o888o o888o `Y8bod8P' o888o o888o o888o `Y888""8o `Y8bod88P" `Y8bod8P'

# This version still need more work,
# wrapping is very tricky


class HomebrewedProfiler: 

    #main registry 
    registry = {}

    #HomebrewedProfiler Parmeters: 

    #please define your plugin main module here, it should be the name of your folder
    plugin_main_module = ""

    #print all event?
    event_prints = True

    #end() parameter
    outputprint=True

    #ignore parameters, typically ui functions/modules
    ignore_fcts = []
    ignore_module = []

    @classmethod
    def register(cls, fct, exec_time=0):
        """update internal registry with exec time and calls"""

        key = f"{fct.__module__}.{fct.__name__}"
        r = cls.registry.get(key)

        if (r is None): 
            cls.registry[key] = {}
            cls.registry[key]["calls"] = 0
            cls.registry[key]["runtime"] = 0
            r = cls.registry[key]

        r["calls"] +=1
        r["runtime"] += exec_time

        return None 

    @classmethod
    def wrapper(cls, fct):
        """wrap-profile any functions with our benchmark & counter"""

        #ignore some function?
        if (fct.__name__ in cls.ignore_fcts):
            return fct

        #Blender might check your function.__code__.co_argcount. this make wrapping way more complex
        #https://stackoverflow.com/questions/73601340/how-to-wrap-a-function-with-accurate-code-argcount?noredirect=1#comment129973896_73601340

        #so fct.__code__.co_argcount will be accurate
        if (fct.__defaults__ is not None):
              posonly = fct.__code__.co_argcount - len(fct.__defaults__)
        else: posonly = fct.__code__.co_argcount

        #ignore some function?
        if (fct.__name__ in cls.ignore_fcts):
            return fct

        import functools
        import time 

        if (posonly==0):

            @functools.wraps(fct)
            def inner(**kwargs):
                t = time.time()
                r = fct(**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==1):

            @functools.wraps(fct)
            def inner(a,**kwargs):
                t = time.time()
                r = fct(a,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==2):

            @functools.wraps(fct)
            def inner(a,b,**kwargs):
                t = time.time()
                r = fct(a,b,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==3):

            @functools.wraps(fct)
            def inner(a,b,c,**kwargs):
                t = time.time()
                r = fct(a,b,c,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==4):

            @functools.wraps(fct)
            def inner(a,b,c,d,**kwargs):
                t = time.time()
                r = fct(a,b,c,d,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==5):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,**kwargs):
                t = time.time()
                r = fct(a,b,c,d,e,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==6):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,**kwargs):
                t = time.time()
                r = fct(a,b,c,d,e,f,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==7):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,**kwargs): 
                t = time.time()
                r = fct(a,b,c,d,e,f,g,**kwargs) 
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==8):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,h,**kwargs):
                t = time.time()
                r = fct(a,b,c,d,e,f,g,h,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==9):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,h,i,**kwargs):
                t = time.time()
                r = fct(a,b,c,d,e,f,g,h,i,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        elif (posonly==10):

            @functools.wraps(fct)
            def inner(a,b,c,d,e,f,g,h,i,j,**kwargs):
                t = time.time()
                r = fct(a,b,c,d,e,f,g,h,i,j,**kwargs)
                cls.register(fct, exec_time=time.time()-t)
                if cls.event_prints: 
                    print(f"PROFILER : {fct.__module__}.{fct.__name__} : {time.time()-t}")
                return r
        
        else:
            raise Exception("PROFILER_ERROR >>> my_wrapper() do not support more than 10 positional argument")

        return inner

    @classmethod
    def start(cls):
        """inject the profiler wrapper for every functions for every modules of our plugin
        used for benchmark or debugging purpose only"""
        
        import sys
        import types

        print("\n","Injecting HomebrewedProfiler","\n")

        def is_function(obj):
            """check if given object is a function"""
            return isinstance(obj, types.FunctionType)
                
        #for all modules in sys.modules
        for mod_k,mod in sys.modules.copy().items():
            
            #separate module componments names
            mod_list = mod_k.split('.')
            
            #fileter module that isn't ours
            if (mod_list[0]!=cls.plugin_main_module):
                continue
            #ignore main __init__ module
            if ((len(mod_list)==1) and (mod_list[0]==cls.plugin_main_module)):
                continue
            #ignore some modules?
            if any([m in cls.ignore_module for m in mod_list]):
                continue
            
            print("HomebrewedProfiler : Module-Search : ",mod_k)
            
            #for each objects found in module
            for ele_k,ele in mod.__dict__.items():
                
                #if it does not have a name, skip
                if (not hasattr(ele,"__name__")):
                    continue
                
                #we have a global function
                elif is_function(ele):
                    print(f"  - Inject : Local-Fct : {mod_k}.{ele_k}")
                    mod.__dict__[ele_k] = cls.wrapper(ele)

                #then we have a homebrewed class?
                elif repr(ele).startswith(f"<class '{cls.plugin_main_module}."):
                    for class_k,class_e in ele.__dict__.items():
                        if is_function(class_e):
                            print(f"  - Inject : Class-Fct : {mod_k}.{ele_k}.{class_k}")
                            setattr( mod.__dict__[ele_k], class_k, cls.wrapper(class_e),) #class.__dict__ are mapping proxies, need to assign this way
                continue

        print("")

        return None 

    @classmethod
    def end(cls,):
        """calculate averages & optionally print output"""

        print("\n","Generating HomebrewedProfiler Sum","\n")

        for k,v in cls.registry.copy().items():
            cls.registry[k]["averagetime"] = v["runtime"]/v["calls"]

        if cls.outputprint: 

            print("\n","Outputing HomebrewedProfiler Result","\n")

            sorted_registry = dict(sorted(cls.registry.items(), key=lambda item:item[1]["runtime"], reverse=False))

            for k,v in sorted_registry.items():
                print("\n",k,":")
                for a,val in v.items():
                    print(" "*6,a,":",val)

        return None

# ooooo                              oooo                                                        .  
# `888'                              `888                                                      .o8  
#  888  ooo. .oo.  .oo.   oo.ooooo.   888   .ooooo.  ooo. .oo.  .oo.    .ooooo.  ooo. .oo.   .o888oo
#  888  `888P"Y88bP"Y88b   888' `88b  888  d88' `88b `888P"Y88bP"Y88b  d88' `88b `888P"Y88b    888  
#  888   888   888   888   888   888  888  888ooo888  888   888   888  888ooo888  888   888    888  
#  888   888   888   888   888   888  888  888    .o  888   888   888  888    .o  888   888    888 .
# o888o o888o o888o o888o  888bod8P' o888o `Y8bod8P' o888o o888o o888o `Y8bod8P' o888o o888o   "888"
#                          888
#                         o888o

#Implementation proposal, in main __init__.register/unregister


"""

#####################################
######## Profiler Parameters ########
#####################################

#Homebrewed profiler & options
from . profiler import HomebrewedProfiler
HomebrewedProfiler.plugin_main_module = "Scatter5"
HomebrewedProfiler.event_prints = True #print live execution?
HomebrewedProfiler.outputprint = True #print final stats?
HomebrewedProfiler.ignore_fcts = ["get_psy_active"] #ignore functions usedin ui?
HomebrewedProfiler.ignore_module = ["ui"] #do not profile some sub modules?

#cProfile profiler & options
from . profiler import cProfiler
cProfiler.outputprint = False #print final stats?
cProfiler.outputlog = True #write log (will overwrite old log)
cProfiler.runviz = True #try to run vizualisation sofware?
cProfiler.vizapp = "snakeviz" #snakeviz|tuna ? use "pip install x" first

#Choose your profiler type
ChosenProfiler = HomebrewedProfiler 

#Turn Profiler on/off here
use_profiler = True 

#####################################
########   Implementation   #########
#####################################

def register():

    #use profiler?
    if use_profiler:
        ChosenProfiler.start()

    for m in main_modules:
        m.register()
    
    return None


def unregister():

    for m in reversed(main_modules):
        m.unregister()

    #final step, remove modules from sys.modules 
    cleanse_modules()

    #output profiler result? 
    if use_profiler:
        ChosenProfiler.end()

    return None


"""
added 3924 characters in body
Source Link
Fox
  • 2.1k
  • 22
  • 49
Loading
Source Link
Fox
  • 2.1k
  • 22
  • 49
Loading