[QUESTION] Timing for GCHP spent on writing restart files

[1Dandan]

Description

Hi, I am following the timing interpretation posted at #194, but still have difficulties in understanding the time spent for Run Exclusive (16715.908 here) and estimating the time spent on writing restart files. The timing outputs for my standard C360 simulation at version 13.2.1 are attached below.

My questions are: 1) How can we get a rough estimate for the time spent on writing restart files?

It looks like the restart files is written by the source code of <gchp-repo>/src/MAPL/base/MAPL_IO.F90, while diagnostics are written by the source code under <gchp-repo>/src/MAPL/gridcomps/History. Therefore, the time for writing restart files is not counted under Run::HIST, but I think it makes sense to include writing restarts in the time spent on Output. For yearlong simulations at high resolution, I usually enable writing daily restart files. Thus this time accounts for a significant amount of total wall time. Getting an estimate would be very helpful.

2) Is waiting for chemistry the dominant contributor for the time spent onRun Exclusive? Or which processes are included in Run Exclusive?

3) Also, another minor question about the timing decomposition, though I am not sure whether it is proper to ask here. Is Run::GCHP::GCHPctmEnv treated as Data conversion in the Fig.6 (attached below) in the recent GCHP paper?

Many thanks!

                                                                Inclusive        Exclusive
                                                             ================ ================
 Name                                               #-cycles  T (sec)    %     T (sec)    %
                                                    -------- --------- ------ --------- ------
 All                                                       1 58353.891 100.00     2.530   0.00
 ...truncated here...
 --Run                                                     1 57448.880  98.45 16715.908  28.65
 ----EXTDATA                                            1740  1257.360   2.15  1257.360   2.15
 ----GCHP                                               3480 24721.812  42.37   145.032   0.25
 ------GCHPctmEnv                                       3480   377.873   0.65   377.873   0.65
 ------GCHPchem                                         3480 18956.756  32.49 18956.756  32.49
 ------DYNAMICS                                         3480  5242.150   8.98  5242.150   8.98
 ----HIST                                               3480 14753.801  25.28 14753.801  25.28
...truncated here...

[lizziel]

Hi @1Dandan, I will attempt to answer these questions here but will also tag several of the NASA MAPL developers as they are the experts on MAPL. Please be aware that the version of MAPL you are using is rather old (2.6.3). GCHP 14.0 has a more recent version (2.18.3) with new and improved timing output, although it does not have an entry specifically for restart file writing. @tclune, @bena-nasa

1)

How can we get a rough estimate for the time spent on writing restart files? It looks like the restart files is written by the source code of <gchp-repo>/src/MAPL/base/MAPL_IO.F90, while diagnostics are written by the source code under <gchp-repo>/src/MAPL/gridcomps/History. Therefore, the time for writing restart files is not counted under Run::HIST, but I think it makes sense to include writing restarts in the time spent on Output. For yearlong simulations at high resolution, I usually enable writing daily restart files. Thus this time accounts for a significant amount of total wall time. Getting an estimate would be very helpful.

I agree it would be a good feature to add a timer for writing restarts. However, it is more complicated than adding it to History. Each gridded component that has an internal state will have a restart file written unless you specify suppressing the write. For GCHP we actually only have one gridded component with an internal state, what we call "GCHPchem" in the code and in the timers output. This makes it seem like the entire model has one restart file but in fact it has the capability for many, an important feature when MAPL is used in GEOS which has many gridded components.

History is a separate gridded component that is specialized for diagnostic computation and output. Adding restarts timing to History would therefore not make sense. My guess is the restart timing is part of the reported time for the individual grid comps, e.g. in GEOSchem for the GCHP restart file, but I am not certain on this. NASA GMAO developers likely know the answer this this.

Are you using the o-server to write restarts? This is a switch in config file GCHP.rc. Depending on whether the answer is yes or no the timing will likely be different. This may impact how the timers are implemented and the timing for restart write reported. Again, I would defer to NASA GMAO on the details.

2)

Is waiting for chemistry the dominant contributor for the time spent onRun Exclusive? Or which processes are included in Run Exclusive?

We have not broken down the timing for the non-sub-processes in GCHPchem run, at least to my knowledge, and so do not know if the majority is wait time, although we suspect it is. You could add additional timers and look at their stats to further investigate. See the GCHP ReadTheDocs post for guidance on this. You could also force all processors to catch up to each other before and after chemistry using VM_Barrier calls and see how that impacts run-time. The GCHPchem Run command is in GEOS-Chem file Interfaces/GCHP/Chem_GridCompMod.F90. I believe the sub-processes excluded from Run Exclusive are the sub-calls within it.

3)

Also, another minor question about the timing decomposition, though I am not sure whether it is proper to ask here. Is Run::GCHP::GCHPctmEnv treated as Data conversion in the Fig.6 (attached below) in the recent GCHP paper?

I am pinging co-authors @LiamBindle and @sdeastham on this. I am not sure what timer(s) that label is referring to. It likely is GCHPctmEnv, which is an interface gridded component between GCHPchem and DYNAMICS, but they should be able to verify.

[1Dandan]

Thanks @lizziel for detailed explanation! It is much clearer to me. Regarding to the restart file writing, I disabled writing restarts by o-server.

[mathomp4]

One (obvious) note is that using the MAPL oserver to write checkpoints is only useful if you are dumping checkpoints in the middle of a run.[^1] There is no benefit if the checkpointing is only done end since you have no "asynchronicity" to exploit.

[^1]: Well, in the past we found that we had to use the oserver to write restarts with Open MPI because of speed issues with the "regular" path. Never figured out why. I don't know if that's still the case, but I think we still default in GEOS to using that if Open MPI.

[lizziel]

We found we needed to use the o-server if using a large number of cores with OpenMPI. GCHP default is o-server is off, but it is automatically turned on if using >1000 cores.

[mathomp4]

We found we needed to use the o-server if using a large number of cores with OpenMPI. GCHP default is o-server is off, but it is automatically turned on if using >1000 cores.

@lizziel Interesting. We do not see that at NCCS. But perhaps we might need to use it at NAS when running at scale. I know I often have...struggles with MPT.

[lizziel]

@1Dandan, I will close out this issue now. There is now a feature request to add timers for writing restarts (https://github.com/GEOS-ESM/MAPL/issues/1887). I'm sorry there have been no responses to your question about the paper.