Add tree output of profiling data
Description
Output the nested profiling data as a full nested tree; store the timing of each child in the profile.
Print out the percentage of the total time and of the parent time.
Save this to a separate file. This feature can be enabled by ProfilingOutputTree = yes
.
Example output:
Tree level, region % of total % of parent Full time
| COMPLETE_RUN 100.00% 100.00% 2.1715
-| ELECTRONS_CONSTRUCTOR 5.88% 5.88% 0.1277
--| MESH_INIT 2.50% 42.52% 0.0543
---| MESH_LABEL 2.47% 87.51% 0.0537
----| MESH_LABEL_REDUCE 0.00% 0.02% 0.0000
-| MESH_INIT 0.32% 0.32% 0.0070
--| MESH_LABEL 2.47% 87.51% 0.0537
---| MESH_LABEL_REDUCE 0.00% 0.02% 0.0000
-| HAMILTONIAN_ELEC_INIT 25.81% 25.81% 0.5605
-| EPOT_GENERATE 0.13% 0.13% 0.0027
--| EPOT_LOCAL 0.11% 84.50% 0.0023
---| SPECIES_GET_LOCAL 0.09% 85.16% 0.0020
---| SUBMESH_INIT 0.01% 6.79% 0.0002
--| SUBMESH_INIT 0.00% 1.71% 0.0000
--| ION_ION_INTERACTION 0.00% 0.05% 0.0000
-| ATOM_COLORING 0.00% 0.00% 0.0000
-| HAMILTONIAN_ELEC_UPDATE 0.01% 0.01% 0.0002
-| CALC_MODE 62.04% 62.04% 1.3472
--| HAMILTONIAN_ELEC_UPDATE 0.01% 0.01% 0.0001
--| BATCH_SET_ZERO 0.06% 0.09% 0.0012
--| RESTART_READ 0.19% 0.31% 0.0041
---| zRESTART_READ_IO 0.08% 40.25% 0.0017
---| zBATCH_SET_STATE 0.10% 50.32% 0.0021
--| CALC_DENSITY 0.02% 0.03% 0.0004
--| KOHN_SHAM_CALC 1.14% 1.84% 0.0247
---| XC 29.68% 98.49% 0.6446
----| XC_LOCAL 28.24% 95.15% 0.6133
-----| LIBXC 24.35% 86.22% 0.5288
-----| BLAS_AXPY_2 0.12% 0.41% 0.0025
----| dMF_DOTP 0.08% 0.27% 0.0018
----| zEIGENVALUE_CALC 1.22% 4.12% 0.0265
-----| BATCH_DO_PACK 0.00% 0.03% 0.0000
-----| zHAMILTONIAN 0.97% 62.81% 0.0211
------| BATCH_SET_ZERO 0.50% 3.47% 0.0109
------| BATCH_DO_PACK 0.00% 0.01% 0.0000
------| zSET_BC 1.35% 9.32% 0.0294
------| BATCH_DO_UNPACK 0.00% 0.01% 0.0000
------| zKINETIC_START 0.00% 0.03% 0.0001
------| zVNLPSI_MAT_BRA 0.16% 1.11% 0.0035
------| zKINETIC_FINISH 8.81% 60.68% 0.1912
-------| zNL_OPERATOR_BATCH 8.80% 99.91% 0.1910
------| zVLPSI 3.47% 23.95% 0.0755
------| zVNLPSI_MAT_KET 0.16% 1.08% 0.0034
-------| zPROJ_MAT_SCATTER 0.07% 46.24% 0.0016
------| zEXCHANGE_OPERATOR 0.00% 0.00% 0.0000
-----| zDOTPV_BATCH 0.54% 35.05% 0.0118
-----| BATCH_DO_UNPACK 0.00% 0.02% 0.0000
--| dMF_DOTP 0.00% 0.00% 0.0000
--| zEIGENVALUE_CALC 0.17% 0.27% 0.0036
---| BATCH_DO_PACK 0.00% 0.03% 0.0000
---| zHAMILTONIAN 0.97% 62.81% 0.0211
----| BATCH_SET_ZERO 0.50% 3.47% 0.0109
----| BATCH_DO_PACK 0.00% 0.01% 0.0000
----| zSET_BC 1.35% 9.32% 0.0294
----| BATCH_DO_UNPACK 0.00% 0.01% 0.0000
----| zKINETIC_START 0.00% 0.03% 0.0001
----| zVNLPSI_MAT_BRA 0.16% 1.11% 0.0035
----| zKINETIC_FINISH 8.81% 60.68% 0.1912
-----| zNL_OPERATOR_BATCH 8.80% 99.91% 0.1910
----| zVLPSI 3.47% 23.95% 0.0755
----| zVNLPSI_MAT_KET 0.16% 1.08% 0.0034
-----| zPROJ_MAT_SCATTER 0.07% 46.24% 0.0016
----| zEXCHANGE_OPERATOR 0.00% 0.00% 0.0000
---| zDOTPV_BATCH 0.54% 35.05% 0.0118
---| BATCH_DO_UNPACK 0.00% 0.02% 0.0000
--| BATCH_DO_PACK 0.00% 0.00% 0.0000
--| BATCH_DO_UNPACK 0.00% 0.00% 0.0000
--| POISSON_SOLVE 0.11% 0.18% 0.0025
---| POISSON_CORRECT 1.45% 53.77% 0.0315
----| BLAS_AXPY_2 0.29% 20.27% 0.0064
----| dMF_DOTP 0.38% 26.19% 0.0082
----| BLAS_COPY_2 0.04% 3.02% 0.0010
---| dMESH_TO_CUBE 0.10% 3.87% 0.0023
---| dOP_APPLY 0.78% 29.11% 0.0170
----| dFFT_FORWARD 0.39% 49.42% 0.0084
----| dG_APPLY 0.04% 5.26% 0.0009
----| dFFT_BACKWARD 0.35% 45.05% 0.0077
---| dCUBE_TO_MESH 0.04% 1.30% 0.0008
--| TD_WRITE_ITER 0.03% 0.05% 0.0007
---| dMF_INTEGRATE 0.07% 22.08% 0.0015
--| TD_WRITE_DATA 0.00% 0.00% 0.0001
--| TD_WRITE_DATA 0.00% 0.00% 0.0000
---| OUTPUT_ALL 0.00% 35.29% 0.0000
--| TIME_STEP 59.99% 96.69% 1.3026
---| TD_WRITE_ITER 0.29% 0.49% 0.0063
----| dMF_INTEGRATE 0.07% 22.08% 0.0015
---| TD_WRITE_DATA 0.00% 0.00% 0.0000
---| TD_WRITE_DATA 0.00% 0.00% 0.0000
----| OUTPUT_ALL 0.00% 35.29% 0.0000
---| TD_PROPAGATOR 59.04% 98.43% 1.2821
----| HAMILTONIAN_ELEC_UPDATE 0.10% 0.17% 0.0022
----| KOHN_SHAM_CALC 29.00% 49.12% 0.6297
-----| XC 29.68% 98.49% 0.6446
------| XC_LOCAL 28.24% 95.15% 0.6133
-------| LIBXC 24.35% 86.22% 0.5288
-------| BLAS_AXPY_2 0.12% 0.41% 0.0025
------| dMF_DOTP 0.08% 0.27% 0.0018
------| zEIGENVALUE_CALC 1.22% 4.12% 0.0265
-------| BATCH_DO_PACK 0.00% 0.03% 0.0000
-------| zHAMILTONIAN 0.97% 62.81% 0.0211
--------| BATCH_SET_ZERO 0.50% 3.47% 0.0109
--------| BATCH_DO_PACK 0.00% 0.01% 0.0000
--------| zSET_BC 1.35% 9.32% 0.0294
--------| BATCH_DO_UNPACK 0.00% 0.01% 0.0000
--------| zKINETIC_START 0.00% 0.03% 0.0001
--------| zVNLPSI_MAT_BRA 0.16% 1.11% 0.0035
--------| zKINETIC_FINISH 8.81% 60.68% 0.1912
---------| zNL_OPERATOR_BATCH 8.80% 99.91% 0.1910
--------| zVLPSI 3.47% 23.95% 0.0755
--------| zVNLPSI_MAT_KET 0.16% 1.08% 0.0034
---------| zPROJ_MAT_SCATTER 0.07% 46.24% 0.0016
--------| zEXCHANGE_OPERATOR 0.00% 0.00% 0.0000
-------| zDOTPV_BATCH 0.54% 35.05% 0.0118
-------| BATCH_DO_UNPACK 0.00% 0.02% 0.0000
----| BLAS_AXPY_2 0.06% 0.11% 0.0013
----| dMF_DOTP 0.01% 0.02% 0.0003
----| zEIGENVALUE_CALC 0.15% 0.26% 0.0033
-----| BATCH_DO_PACK 0.00% 0.03% 0.0000
-----| zHAMILTONIAN 0.97% 62.81% 0.0211
------| BATCH_SET_ZERO 0.50% 3.47% 0.0109
------| BATCH_DO_PACK 0.00% 0.01% 0.0000
------| zSET_BC 1.35% 9.32% 0.0294
------| BATCH_DO_UNPACK 0.00% 0.01% 0.0000
------| zKINETIC_START 0.00% 0.03% 0.0001
------| zVNLPSI_MAT_BRA 0.16% 1.11% 0.0035
------| zKINETIC_FINISH 8.81% 60.68% 0.1912
-------| zNL_OPERATOR_BATCH 8.80% 99.91% 0.1910
------| zVLPSI 3.47% 23.95% 0.0755
------| zVNLPSI_MAT_KET 0.16% 1.08% 0.0034
-------| zPROJ_MAT_SCATTER 0.07% 46.24% 0.0016
------| zEXCHANGE_OPERATOR 0.00% 0.00% 0.0000
-----| zDOTPV_BATCH 0.54% 35.05% 0.0118
-----| BATCH_DO_UNPACK 0.00% 0.02% 0.0000
----| POISSON_SOLVE 2.58% 4.37% 0.0561
-----| POISSON_CORRECT 1.45% 53.77% 0.0315
------| BLAS_AXPY_2 0.29% 20.27% 0.0064
------| dMF_DOTP 0.38% 26.19% 0.0082
------| BLAS_COPY_2 0.04% 3.02% 0.0010
-----| dMESH_TO_CUBE 0.10% 3.87% 0.0023
-----| dOP_APPLY 0.78% 29.11% 0.0170
------| dFFT_FORWARD 0.39% 49.42% 0.0084
------| dG_APPLY 0.04% 5.26% 0.0009
------| dFFT_BACKWARD 0.35% 45.05% 0.0077
-----| dCUBE_TO_MESH 0.04% 1.30% 0.0008
----| BLAS_COPY_2 0.37% 0.63% 0.0081
----| ELEC_FUSE_DENS_EXP_APPLY 26.39% 44.70% 0.5731
-----| CALC_DENSITY 0.46% 1.74% 0.0100
-----| BATCH_DO_PACK 0.00% 0.00% 0.0000
-----| BATCH_DO_UNPACK 0.00% 0.00% 0.0000
-----| EXP_TAYLOR_BATCH 25.85% 97.96% 0.5614
------| zHAMILTONIAN 13.54% 52.37% 0.2940
-------| BATCH_SET_ZERO 0.50% 3.47% 0.0109
-------| BATCH_DO_PACK 0.00% 0.01% 0.0000
-------| zSET_BC 1.35% 9.32% 0.0294
-------| BATCH_DO_UNPACK 0.00% 0.01% 0.0000
-------| zKINETIC_START 0.00% 0.03% 0.0001
-------| zVNLPSI_MAT_BRA 0.16% 1.11% 0.0035
-------| zKINETIC_FINISH 8.81% 60.68% 0.1912
--------| zNL_OPERATOR_BATCH 8.80% 99.91% 0.1910
-------| zVLPSI 3.47% 23.95% 0.0755
-------| zVNLPSI_MAT_KET 0.16% 1.08% 0.0034
--------| zPROJ_MAT_SCATTER 0.07% 46.24% 0.0016
-------| zEXCHANGE_OPERATOR 0.00% 0.00% 0.0000
------| BATCH_COPY_DATA_TO 5.64% 21.80% 0.1224
------| zBATCH_AXPY_CONST 2.35% 9.10% 0.0511
-------| BLAS_AXPY_4 2.35% 99.77% 0.0510
------| dBATCH_AXPY_CONST 2.79% 10.80% 0.0606
-------| BLAS_AXPY_4 2.78% 99.79% 0.0605
----| ELEC_MOVE_IONS 0.00% 0.00% 0.0000
----| ELEC_MOVE_GAUGE 0.00% 0.00% 0.0000
----| ELEC_UPDATE_H 0.03% 0.05% 0.0007
-----| HAMILTONIAN_ELEC_UPDATE 0.03% 99.38% 0.0007
---| RESTART_WRITE 0.41% 0.68% 0.0089
----| zBATCH_GET_STATE 0.06% 15.48% 0.0014
----| zDISK_WRITE 0.30% 72.95% 0.0065
---| zDISK_WRITE 0.12% 0.21% 0.0027
// modeline for vim to enable folding (put in ~/.vimrc: set modeline modelineexpr)
// vim: fdm=expr fde=getline(v\:lnum)=~'.*\|.*'?len(split(getline(v\:lnum))[0])-1\:0
News snippet
Add tree output of profiling data
Checklist
-
I have checked that my code follows the Octopus coding standards -
I have added tests for all the new features added in this request.
Edited by Sebastian Ohlmann