#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
"""
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
cProfile
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 ( usepip 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 ( usepip install
first of course)
Find hereby two profilers class with an implementation proposal/example
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
"""