Skip to content

Add tree output of profiling data

Sebastian Ohlmann requested to merge profiling_tree into develop

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

Merge request reports