I created a decorator @t that I add before @njit. A problem arises when one function using @njit calls another with both @t and @njit. I end up removing the decorator in these instances. Otherwise I get this error: Untyped global name 'example_function': cannot determine Numba type of <class 'function'>. I’d like to be able to continue seeing the results for each function.
results = {}
def t(f):
def wrapper(*args, **kwargs):
start = time.time()
for i in range(1):
g = f(*args)
run_time = time.time() - start
if f.__name__ in results:
results[f.__name__] += [run_time]
else:
results[f.__name__] = [run_time]
return g
return wrapper
def profile_results():
l = []
for k in results:
a = np.asarray(results[k])
# print(k, ' '*(15-len(k)), np.sum(a[1:]))
l += [[k+' '*(13-len(k)), np.sum(a[1:])]]
l = sorted(l, key=lambda x: x[1])
for i in range(len(l)):
print( l[i][0], "{:.6f}".format( l[i][1] ) )
I believe the pattern in general is compatible, as I have heard of other people combining decorators with @njit - If you could post an executable reproducer I could look into this further a bit more easily.
You get an error because while njit(foo) is a valid jitted function (CPUDispatcher in Numba terminology), t(njit(foo)) is a normal Python function and cannot be called from bar, which is jitted.
I’m very interested in this problem, since there’s no other way to measure the per-function execution time. @gmarkall is there any way to have a global dictionary? Unfortunately typed dicts cannot be lowered as constants (https://github.com/numba/numba/issues/4062#issuecomment-490488298). I wonder if there’s any trick that could be used to get a reference to a global dictionary.
Here’s code that demonstrates the issue in a mini use case.
import time
import numpy as np
from numba import njit, jit
results = {}
def t(f):
def wrapper(*args, **kwargs):
start = time.time()
for i in range(1):
g = f(*args)
run_time = time.time() - start
if f.__name__ in results:
results[f.__name__] += [run_time]
else:
results[f.__name__] = [run_time]
# print( time.time() - start, f.__name__ )
return g
return wrapper
# @t #This line causes an issue
@njit
def ahp(x, t, u, A):
return -A * np.sum( np.exp( (x-t) / u ) )
@njit
def line_intercept(y1, y2, thresh):
#this is really a ratio
# print(y1, y2)
return 1 - (thresh-y1)/(y2-y1)
@t
@njit
def get_spikes(c, threshold, u, A):
st = []
y = np.zeros(c.size)
for xt in range(0, c.size):
a = ahp(np.asarray(st), xt, u, A)
y[xt] = c[xt] + a
if threshold < y[xt]:
li = line_intercept(y[xt-1], y[xt], threshold)
st.append(xt-li)
# st.append(xt)
return (np.asarray(st), y)
@t
def test_sim():
np.random.seed(0)
x = np.random.uniform(-1,1,200)
st, y = get_spikes(x, np.max(x)/2, 1.2, 100)
def profile_results():
l = []
for k in results:
a = np.asarray(results[k])
# print(k, ' '*(15-len(k)), np.sum(a[1:]))
l += [[k+' '*(13-len(k)), np.sum(a[1:])]]
l = sorted(l, key=lambda x: x[1])
for i in range(len(l)):
print( l[i][0], "{:.6f}".format( l[i][1] ) )
if __name__ == '__main__':
test_sim()
test_sim()
profile_results()
import time
import numpy as np
from numba import njit, jit, objmode
results = {}
def jit_timer(f):
jf = njit(f)
@njit
def wrapper(*args):
with objmode(start='float64'):
start = time.time()
g = jf(*args)
with objmode():
end = time.time()
run_time = end - start
if f.__name__ in results:
results[f.__name__] += [run_time]
else:
results[f.__name__] = [run_time]
return g
return wrapper
@njit
def pointless_delay(seconds):
with objmode():
s = time.time()
e = 0
while (e < seconds):
e = time.time() - s
@jit_timer
def ahp(x, t, u, A):
pointless_delay(1) # 1s delay
# total delay is 1s
@jit_timer
def line_intercept(y1, y2, thresh):
pointless_delay(1) # 1s delay
# total delay is 1s
@jit_timer
def get_spikes(c, threshold, u, A):
pointless_delay(2) # 2s delay
ahp(None, None, None, None) # 1s delay
line_intercept(None, None, None) # 1s delay
# total delay is 4s
@jit_timer
def test_sim():
pointless_delay(7) # 7s delay
get_spikes(None, 2, 1.2, 100) # 4s delay
# total delay is 11s
def profile_results():
l = []
for k in results:
a = np.asarray(results[k])
l += [[k+' '*(13-len(k)), np.sum(a[1:])]]
l = sorted(l, key=lambda x: x[1])
for i in range(len(l)):
print( l[i][0], "{:.6f}".format( l[i][1] ) )
if __name__ == '__main__':
test_sim()
test_sim()
profile_results()
@stuartarchibald, yes! That definitely helps, thanks so much! I didn’t know about object mode. This is a cool way to use it. I just checked and it works and now I can see the results of all of those other functions too. I like this @jit_timer!
I played with the timer a bit more and realized I could use very similar code to make a dependency graph with it too. Thought you folks might enjoy this.
results = {}
tree = {'stack':['main'], 'main':set()}
def wrapper_objm_start(f):
start = time.time()
tree[ tree['stack'][-1] ].add( f.__name__ )
tree['stack'] += [ f.__name__ ]
if f.__name__ not in results:
tree[f.__name__] = set()
# print(tree['stack'])
return start
def wrapper_objm_end(f, start):
run_time = time.time() - start
if f.__name__ in results:
results[f.__name__] += [run_time]
else:
results[f.__name__] = [run_time]
tree['stack'] = tree['stack'][:-1]
def t(f):
def wrapper(*args, **kwargs):
start = wrapper_objm_start(f)
g = f(*args)
wrapper_objm_end(f, start)
return g
return wrapper
def jit_timer(f):
jf = njit(f)
@njit
def wrapper(*args):
with objmode(start='float64'):
start = wrapper_objm_start(f)
g = jf(*args)
with objmode():
wrapper_objm_end(f, start)
return g
return wrapper
Here’s some output from a sample run of mine. You can see that I can run different implementations of the same functionality (conv_1d1o and nbconv_1d1o) and compare their run time.
The code to print the tree with the times can be done simply. It’d be neat to have a decorator built into numba that did something like this, especially since the way it works now is limited because of the global variables.
def print_tree(node, layer):
for n in node:
print('{:.6f}'.format( np.min(results[n]) ), '-|-'*layer, n)
print_tree(tree[n], layer+1)
Cool stuff
I think this can definitely be helpful in certain situations, even just for following call chains alone.
I guess that one has to keep in mind that for short running (and repeatedly called) functions the decorator itself could dominate the runtime, especially due to the context switching back into the interpreter. Possibly this also blocks certain compiler optimisations like inlining?.
@randompast very nice expect others will find this or similar of use!
@Hannes indeed, your assessment is correct, coarse grained functions will work best with the approach above, it will also likely have knock-on effects in optimisation which may also skew results. For more fine grained/general profiling something like this https://github.com/numba/numba/issues/5028 is needed. I just need a decent tranche of time to get it into production as it’s somewhat involved!
@stuartarchibald, would the line profiling in #5028 also provide function level profiling? Or would those be two different features?
@randompast the tree is a great addition! If I have time, I’ll try to add some information about the number of times a function is compiled (since excessive compilation can also be a performance problem). I think this decorator is a perfect example of the kind of things to put in the add-ons package (Addons / Contrib repo).
This decorator has been increasingly causing me trouble. Since it uses global variables it can’t use the cached version. Each time the file is run, the njit functions need to be recompiled.
This decorator has been increasingly causing me trouble. Since it uses global variables it can’t use the cached version. Each time the file is run, the njit functions need to be recompiled.
