1. Table of Contents
2. Profilers
I use two profilers:
cProfile - https://docs.python.org/3/library/profile.html
line-profiler - https://pypi.org/project/line-profiler/
3. Requirements
python 3.10: module load itm-python/3.10
line-profiler : pip install line-profiler
gprof2dot : pip install gprof2dot
4. How to run?
- Prepare a standard launch
- Copy
pythondirectory from/gss_efgw_work/work/g2fjc/jintrac/v220922/pythonto some location onpfsfor example:/pfs/work/g2pbloch/python(I use paths with my username, change them to ones with your username) - Change
JINTRAC_PYTHON_DIRin rjettov (430 line) to python directory on pfs from step 2 - Change
run_python_driver (line 49)in/pfs/work/g2pbloch/python(I use paths with my username, change them to ones with your username): - cProfile :
mpirun --allow-run-as-root -np $NPROC python -u -m cProfile -o jintrac.prof /pfs/work/g2pbloch/python/jintrac_imas_driver.py mpi - line-profiler :
mpirun --allow-run-as-root -np $NPROC python -u -m kernprof -l /pfs/work/g2pbloch/python/jintrac_imas_driver.py mpi When we use line-profiler we must add wrapper to profiling function. In this case we should add
@profileupperjintrac_imas_driverfunction injintrac_imas_driver.py:function wrapper@profile def jintrac_imas_driver(params, components, mpi='no'): """JINTRAC-IMAS generic workflow driver."""- Run
./rjettov -S -I -p -x64 test v220922 g2fjc
5. cProfile analysis
To read data from test.prof we need python script. We can use e.g.
import pstats
stats = pstats.Stats('test.prof')
stats.strip_dirs().sort_stats(pstats.SortKey.TIME).print_stats()
This script print data sorted by tottime column ( In tottime column is total time spent in the given function (and excluding time made in calls to sub-functions)). These are the first few lines of the result:
Wed Nov 30 09:40:33 2022 test.prof
19379745 function calls (19376063 primitive calls) in 164.514 seconds
Ordered by: internal time
ncalls tottime percall cumtime percall filename:lineno(function)
3 81.304 27.101 81.304 27.101 {imas_3_37_0_ual_4_11_0._ual_lowlevel.ual_open_pulse}
2891220 42.947 0.000 52.709 0.000 {imas_3_37_0_ual_4_11_0._ual_lowlevel.ual_read_data_array}
2497358 16.127 0.000 16.127 0.000 {imas_3_37_0_ual_4_11_0._ual_lowlevel.ual_read_data_scalar}
2899948 2.784 0.000 2.784 0.000 {built-in method numpy.zeros}
815194 2.391 0.000 2.391 0.000 {method 'reduce' of 'numpy.ufunc' objects}
427578 1.225 0.000 2.589 0.000 fromnumeric.py:38(_wrapit)
815196 1.015 0.000 7.988 0.000 {built-in method numpy.core._multiarray_umath.implement_array_function}
387616 0.876 0.000 2.809 0.000 fromnumeric.py:69(_wrapreduction)
427578 0.848 0.000 0.848 0.000 {method 'reshape' of 'numpy.ndarray' objects}
427578 0.685 0.000 3.358 0.000 fromnumeric.py:51(_wrapfunc)
387785 0.684 0.000 0.684 0.000 {method 'items' of 'dict' objects}
Complete file is below:
We can also make an image from data:
- Install gprof2dot :
pip install gprof2dot - run :
python -m gprof2dot -f pstats test.prof | dot -Tsvg -o output.svg
Example image looks like this ( output.svg is simplified image, output1.svg is complete image with full data):
6. Line-profiler analysis
To read data from jintrac_imas_driver.py.lprof run:
-
python -m line_profiler jintrac_imas_driver.py.lprof.
These are the first few lines of the results :
Timer unit: 1e-06 s Total time: 232.892 s File: /pfs/work/g2pbloch/python/jintrac_imas_driver.py Function: jintrac_imas_driver at line 721 Line # Hits Time Per Hit % Time Line Contents ============================================================== 721 @profile 722 def jintrac_imas_driver(params, components, mpi='no'): 723 724 """JINTRAC-IMAS generic workflow driver.""" 725 726 # Workflow configuration parameters 727 728 1 5.9 5.9 0.0 user_in = wf.string(params, "Input IDS user") 729 1 2.3 2.3 0.0 machine_in = wf.string(params, "Input IDS machine") 730 1 4.7 4.7 0.0 shot_in = wf.integer(params, "Input IDS shot") 731 1 2.1 2.1 0.0 run_in = wf.integer(params, "Input IDS run") 732 1 2.9 2.9 0.0 user_out = wf.string(params, "Output IDS user") 733 1 2.6 2.6 0.0 machine_out = wf.string(params, "Output IDS machine") 734 1 2.6 2.6 0.0 shot_out = wf.integer(params, "Output IDS shot") 735 1 2.6 2.6 0.0 run_out = wf.integer(params, "Output IDS run") 736 1 13.3 13.3 0.0 user_tmp = os.environ['HOME']+'/public/tempdb'
Complete file is below:
Key lines from the results:
Line # Hits Time Per Hit % Time Line Contents
895 1 62545203.7 62545203.7 26.9 alenv = ALEnv(user_temp=user_tmp)
917 22 49496025.7 2249819.4 21.3 ids_bundle_input[ids_struct] = eval('DBentry.idsin.get("'+ids_struct+'")')
922 1 83745046.9 83745046.9 36.0 tmpdict = bundle_copy(ids_bundle_input)
956 2 4665617.1 2332808.6 2.0 ids_bundle_input[elem] = DBentry.idsin.get_slice(elem, tstart, 3)
966 1 6353190.5 6353190.5 2.7 ids_bundle_work = bundle_copy(ids_bundle_input)
967 1 7884627.8 7884627.8 3.4 ids_bundle_updated = bundle_copy(ids_bundle_input)
1022 3 14539266.0 4846422.0 6.2 ids_bundle_prev[item] = bundle_copy(ids_bundle_work,imas_control.get_ids_sublist_updates(item))
7. Candidates for bottlenecks
From cProfile result can see that 85% execution time jintrac_imas_driver.py spend on imas functions. Function ual_open_pulse was called only 3 times. It execution time is 27s. Functions ual_read_data_array and ual_read_data_scalar was called more than 2 milions times.
From line-profiler we can see, that jintrac_imas_driver.py spends a lot of time in lins with functioin bundle_copy. This function call imas functions. A lot of time is also taken up by functions calls with DBentry.
Possible ways to speed up jintrac_imas_driver.py:
Reducing number of calls:ual_open_pulse,ual_read_data_array,ual_read_data_scalar