...
| Code Block |
|---|
| title | time [sec] consumption per algorithm and pre entire event |
|---|
| collapse | true |
|---|
|
requested cpu:096
cpu_num:096 nevt:000 time algo/total:0.201525/0.750702
cpu_num:096 nevt:010 time algo/total:0.200815/0.742284
cpu_num:096 nevt:020 time algo/total:0.199862/0.738482
cpu_num:096 nevt:030 time algo/total:0.200478/0.742564
cpu_num:096 nevt:040 time algo/total:0.200695/0.741042
cpu_num:096 nevt:050 time algo/total:0.199134/0.736679
cpu_num:096 nevt:060 time algo/total:0.198478/0.736582
cpu_num:096 nevt:070 time algo/total:0.198812/0.737684
cpu_num:096 nevt:080 time algo/total:0.200575/0.742578
cpu_num:096 nevt:090 time algo/total:0.200512/0.737443 |
2024-01-31 time consumption test in subprocess
Try to resolve mystery observed in previous test:
- time consuming algorithm takes ~200ms
- but time per event is ~740ms
Algorithm code
| Code Block |
|---|
| title | method time_consuming_code |
|---|
| collapse | true |
|---|
|
def time_consuming_algorithm():
t01 = time()
a, b = random_arrays()
t02 = time()
gr1 = a>=11
gr2 = (a>9) & (a<11)
gr3 = a<=9
t03 = time()
a[gr1] -= b[0, gr1]
a[gr2] -= b[1, gr2]
a[gr3] -= b[2, gr3]
t04 = time()
return (t01, t02, t03, t04) |
| Code Block |
|---|
| title | code simulating the event loop |
|---|
| collapse | true |
|---|
|
def do_algo(cpu=0):
hostname = get_hostname()
#cpu_num = psutil.Process().cpu_num()
print('requested cpu:%03d' % cpu)
SAVE_FIGS = True
nevents = 100
ntpoints = 6
arrts = np.zeros((nevents,ntpoints), dtype=np.float64)
t05_old = time()
for nevt in range(nevents):
t00 = time()
times = time_consuming_algorithm()
cpu_num = psutil.Process().cpu_num()
#if cpu_num >=16 and cpu_num <=23:
# print('cpu_num:%03d nevt:%03d time:%.6f CPU_NUM IN WEKA RANGE [16,23]' % (cpu_num, nevt, dt_sec))
t05 = time()
times = (t00,) + times + (t05,)
arrts[nevt,:] = times
dt_evt = t05 - t05_old
t05_old = t05
if nevt%10>0: continue
dt_alg = times[4] - times[3]
dt_in = times[4] - times[1]
print('cpu_num:%03d nevt:%03d times (sec)' % (cpu_num, nevt), \
' random arrs: %.6f' % (times[2] - times[1]), \
' indeces: %.6f' % (times[3] - times[2]), \
' alg: %.6f' % (times[4] - times[3]), \
' inside algo: %.6f' % (times[4] - times[1]), \
' per event: %.6f' % dt_evt)
...
fill-out and show histograms |
Per-event time split
| Code Block |
|---|
| title | per-event time split |
|---|
| collapse | true |
|---|
|
requested cpu:010
cpu_num:010 nevt:000 times (sec) random arrs: 0.530126 indeces: 0.009856 alg: 0.201348 inside algo: 0.741331 per event: 0.742876
cpu_num:010 nevt:010 times (sec) random arrs: 0.529047 indeces: 0.006796 alg: 0.199449 inside algo: 0.735292 per event: 0.736108
cpu_num:010 nevt:020 times (sec) random arrs: 0.529192 indeces: 0.006795 alg: 0.200225 inside algo: 0.736212 per event: 0.736941
cpu_num:010 nevt:030 times (sec) random arrs: 0.529076 indeces: 0.006807 alg: 0.198543 inside algo: 0.734425 per event: 0.735161
cpu_num:010 nevt:040 times (sec) random arrs: 0.529014 indeces: 0.006840 alg: 0.198867 inside algo: 0.734720 per event: 0.735475
cpu_num:010 nevt:050 times (sec) random arrs: 0.529560 indeces: 0.006824 alg: 0.199954 inside algo: 0.736338 per event: 0.737050
cpu_num:010 nevt:060 times (sec) random arrs: 0.529004 indeces: 0.006804 alg: 0.198679 inside algo: 0.734487 per event: 0.735210
cpu_num:010 nevt:070 times (sec) random arrs: 0.528883 indeces: 0.006833 alg: 0.199188 inside algo: 0.734903 per event: 0.735635
cpu_num:010 nevt:080 times (sec) random arrs: 0.528968 indeces: 0.006804 alg: 0.199556 inside algo: 0.735327 per event: 0.736039
cpu_num:010 nevt:090 times (sec) random arrs: 0.528690 indeces: 0.006826 alg: 0.199990 inside algo: 0.735506 per event: 0.736218 |
Summary for time consumption
Random array of shapes sh2d = (8*512,1024) and sh3d = (3, 8*512,1024) simulating raw data and calib constants takes ~0.5sec. In previous code only one array of 2-panel shape (2*512,1024) was produced.
References
