Timer.dat Output detailed

Hello,

I was just wondering what are the 4 columns I get in my output and what do they represent.
Below is the content of the timer.dat file. I apologize for the size but I cannot upload a document as a new user.

Thank you for your help,
Mirna

timer.dat :
Host: glados

Timers On : Mon Oct 15 11:33:13 2018
Timers Off: Mon Oct 15 16:35:25 2018

Wall Time:    18131.96 seconds
#column 1                               column 2   column 3  column 4     column5           
JK: (A|Q)^-1                :    206.400u    179.617s    132.066w    129 calls
JK: (A|mn)                  :   2531.767u      5.933s   1523.118w    297 calls
JK: (Q|mn)                  :   2738.150u      8.383s   1648.373w    297 calls
JK: (Q|mn) Write            :      1.100u    136.067s     82.413w    297 calls
HF: Form H                  :      1.550u      1.017s     67.366w    129 calls
HF: Form S/X                :     30.233u      0.650s     18.564w    129 calls
HF: Guess                   :    137.167u      5.733s     86.075w    129 calls
SAD Guess                   :    136.200u      5.517s     85.309w    129 calls
HF: Form G                  :  11481.467u   1978.000s   8237.641w   1432 calls
JK: D                       :      2.567u      0.067s      1.546w   1432 calls
JK: USO2AO                  :      1.850u      0.000s      1.246w   1432 calls
JK: JK                      :  11473.000u   1976.617s   8231.427w   1432 calls
JK: (Q|mn) Read             :      8.600u    945.283s    572.565w   4031 calls
JK: J                       :    652.933u      3.617s    393.655w   4031 calls
JK: J1                      :    303.550u      1.417s    183.431w   4031 calls
JK: J2                      :    335.617u      1.133s    201.840w   4031 calls
JK: K                       :  10666.883u     24.550s   6416.902w   4031 calls
JK: K1                      :   9050.733u     22.117s   5445.374w   4031 calls
JK: K2                      :   1614.533u      2.267s    970.245w   4031 calls
JK: AO2USO                  :      0.017u      0.017s      0.003w   1432 calls
HF: Form F                  :      2.033u      0.517s      1.604w   1432 calls
HF: DIIS                    :    134.483u     21.717s    101.947w   1432 calls
DIISManager::add_entry      :      2.200u      6.367s     13.416w   1303 calls
DIISManager::extrapolate    :      7.533u     14.167s     13.221w   1174 calls
bMatrix setup               :      1.600u      8.150s      5.992w   1174 calls
bMatrix pseudoinverse       :      0.150u      0.017s      0.111w   1174 calls
New vector                  :      5.750u      6.000s      7.098w   1174 calls
HF: Form C                  :    361.183u      0.733s    217.135w   1432 calls
HF: Form D                  :      1.550u      0.050s      0.944w   1432 calls
DFMP2 Singles               :      6.067u      0.017s      3.651w    129 calls
DFMP2 Aia                   :   5110.450u    154.933s   3175.607w    129 calls
DFMP2 (A|mn)                :   4271.900u      8.967s   2569.185w    645 calls
DFMP2 (A|mn)C_mi            :    254.467u      6.867s    156.865w    645 calls
DFMP2 (A|mi)C_na            :    187.650u      0.750s    113.157w    645 calls
DFMP2 Aia Write             :      0.333u     20.467s     12.452w    645 calls
DFMP2 Qia                   :    654.850u     74.750s    453.506w    129 calls
DFMP2 Metric                :    311.200u      4.783s    189.633w    129 calls
DFMP2 Aia Read              :      0.317u     10.417s      6.360w    129 calls
DFMP2 (Q|A)(A|ia)           :    337.783u      1.300s    203.548w    129 calls
DFMP2 Qia Write             :      0.133u     20.083s     12.155w    129 calls
DFMP2 Energy                :   2197.583u     62.617s   1375.107w    129 calls
DFMP2 Qia Read              :      4.200u     10.250s      8.626w    258 calls

-----------------------------------------------------------
JK: (A|Q)^-1                :    206.400u    179.617s    132.066w    129 calls
JK: (A|mn)                  :   2531.767u      5.933s   1523.118w    297 calls
JK: (Q|mn)                  :   2738.150u      8.383s   1648.373w    297 calls
JK: (Q|mn) Write            :      1.100u    136.067s     82.413w    297 calls
HF: Form H                  :      1.550u      1.017s     67.366w    129 calls
HF: Form S/X                :     30.233u      0.650s     18.564w    129 calls
HF: Guess                   :    137.167u      5.733s     86.075w    129 calls
| SAD Guess                 :    136.200u      5.517s     85.309w    129 calls
HF: Form G                  :  11481.467u   1978.000s   8237.641w   1432 calls
| JK: D                     :      2.567u      0.067s      1.546w   1432 calls
| JK: USO2AO                :      1.850u      0.000s      1.246w   1432 calls
| JK: JK                    :  11473.000u   1976.617s   8231.427w   1432 calls
| | JK: (Q|mn) Read         :      8.600u    945.283s    572.565w   4031 calls
| | JK: J                   :    652.933u      3.617s    393.655w   4031 calls
| | | JK: J1                :    303.550u      1.417s    183.431w   4031 calls
| | | JK: J2                :    335.617u      1.133s    201.840w   4031 calls
| | JK: K                   :  10666.883u     24.550s   6416.902w   4031 calls
| | | JK: K1                :   9050.733u     22.117s   5445.374w   4031 calls
| | | JK: K2                :   1614.533u      2.267s    970.245w   4031 calls
| JK: AO2USO                :      0.017u      0.017s      0.003w   1432 calls
HF: Form F                  :      2.033u      0.517s      1.604w   1432 calls
HF: DIIS                    :    134.483u     21.717s    101.947w   1432 calls
| DIISManager::add_entry    :      2.200u      6.367s     13.416w   1303 calls
| DIISManager::extrapolate  :      7.533u     14.167s     13.221w   1174 calls
| | bMatrix setup           :      1.600u      8.150s      5.992w   1174 calls
| | bMatrix pseudoinverse   :      0.150u      0.017s      0.111w   1174 calls
| | New vector              :      5.750u      6.000s      7.098w   1174 calls
HF: Form C                  :    361.183u      0.733s    217.135w   1432 calls
HF: Form D                  :      1.550u      0.050s      0.944w   1432 calls
DFMP2 Singles               :      6.067u      0.017s      3.651w    129 calls
DFMP2 Aia                   :   5110.450u    154.933s   3175.607w    129 calls
| DFMP2 (A|mn)              :   4271.900u      8.967s   2569.185w    645 calls
| DFMP2 (A|mn)C_mi          :    254.467u      6.867s    156.865w    645 calls
| DFMP2 (A|mi)C_na          :    187.650u      0.750s    113.157w    645 calls
| DFMP2 Aia Write           :      0.333u     20.467s     12.452w    645 calls
DFMP2 Qia                   :    654.850u     74.750s    453.506w    129 calls
| DFMP2 Metric              :    311.200u      4.783s    189.633w    129 calls
| DFMP2 Aia Read            :      0.317u     10.417s      6.360w    129 calls
| DFMP2 (Q|A)(A|ia)         :    337.783u      1.300s    203.548w    129 calls
| DFMP2 Qia Write           :      0.133u     20.083s     12.155w    129 calls
DFMP2 Energy                :   2197.583u     62.617s   1375.107w    129 calls
| DFMP2 Qia Read            :      4.200u     10.250s      8.626w    258 calls

***********************************************************

(I added triple backticks around the file so that it formats nicely.)

So the “u”/“s”/“w” columns are user/system/wall time, which are just three ways of measuring time spent. This and this are better explanations than I can give quickly. The column to the left is a short (and hopefully distinct) label of the time-consuming parts of code hit. The second block of info (below dashed line; rearrangement of first block) shows some hierarchy/nestedness of code calls.

We’d like to export this to a python dictionary additionally for easy analysis, but text file is it for now.

Dear Mirna,

Thanks for bringing up this question. It would be a lot more clear if the columns were labeled! In response to your post, Asem Alenaizan has updated the code so that timer.dat will print column labels (https://github.com/psi4/psi4/pull/1294).

Sincerely,
David Sherrill

Dear David,

Thank you for your reply and Thanks to Asem for the updates.

Dear @loriab,

I did not know how to format it the way you did so thank you for editing it.

Sincerely,
Mirna