E3sm: issues with MPAS components writing from all ranks

[mark-petersen]

Note: This was submitted as an issue to the MPAS repo at:
https://github.com/MPAS-Dev/MPAS/issues/1135
if you have access to MPAS-Dev.

Problem: On some compilers, like IBM on Mira, the current method of write(stderrUnit,...) will write all output to an actual SCRATCH file on disk, rather than dev/nul. On Mira the name of the SCRATCH file is the same for all ranks. All cores try to write to this SCRATCH file at every line with a write(stderrUnit,...). Problem shows up after the first core closes this file, but then other cores try to close a file that is already deleted.

A possible solution to both is to put all write commands in a small wrapper routine, and there we could more carefully specify how output is written, with MPAS_DEBUG and check for master rank. Then for standard non-DEBUG runs, only the master rank ever writes, so all these problems are avoided.

Note:FORTRAN standard says that the same process cannot have multiple opens to dev/nul. This was a problem when multiple MPAS components are running on the same node in ACME, the second open fails on PGI (titan). @douglasjacobsen implemented a fix in ACME so that std_out and std_err was redirected from dev/nul to status=SCRATCH (see MPAS_DEBUG in ocn_comp_MCT.F in ACME driver). That led to problem 1, above. The proposed solution would eliminate the need for this.

[mark-petersen]

This was due to a conversation at the Denver ACME meeting with @amametjanov. CC @worleyph

[worleyph]

"I approve this request". The current solution is to do something different with PGI and other compilers, adding ifdefs directly in the code, and there may be other compiler differences, or compiler/system differences, that show up in the future. A wrapper would isolate this nastiness and allow for a more flexible solution.

[matthewhoffman]

Reopening because #1257 patches this for some machines, but the long-term solution will come with the MPAS logging module I am currently working on. I anticipate a week or so of development on that, but it will also require I would guess a couple weeks of code review by the MPAS team, plus time for each core to convert over dozens or hundreds of write() statements to the new functionality.

[matthewhoffman]

Update: prototype of MPAS log module works as desired within ACME.

The prototype is a complete implementation of the log module infrastructure (the not-so-small wrapper routine) in Fortran. Remaining work is to extend it to the C code in MPAS, complete code review by MPAS developer team, convert all existing framework and core write messages to use the new system.

[amametjanov]

@matthewhoffman sorry to bug, but is there an estimate on when this will make it into ACME submodules? Thank you.

[matthewhoffman]

@amametjanov , this work has been moving along steadily. The new MPAS logging module implementation is complete in the MPAS framework, and I've completed converting over all the write statements in MPAS framework. We are now in the stage of converting over all the existing write statements in each core. After that I can update the ACME drivers for each MPAS component and do testing in ACME to make sure we don't break anything. We are making steady progress, but I think we are probably looking at the first week in April or so before we have a PR ready and tested. (Some people are out all or part of next week for spring break.)

[matthewhoffman]

@amametjanov , Update: MPAS-side changes are finalized, final testing is ongoing in ACME. Expect to see an ACME PR today or, more likely, Monday.

[matthewhoffman]

PR has been created: #1442. We will do additional testing here next week before merging to next. @amametjanov or @worleyph , feel free to do your own testing on machines of interest if you wish.

[ndkeen]

Much thanks for this. My vote for PR I'm most excited to try out. Cori has been swamped recently and I have had little chance to test.

[matthewhoffman]

Thanks for the feedback. It ended up being quite a lot of work to get fully implemented, so I hope it turns out to indeed make things easier.

[amametjanov]

@matthewhoffman I noticed that some runs (e.g. -compset A_WCYCL2000_H01AS -res ne120_oRRS18v3_ICG -mach mira) now produce log.ocean.<proc-id>.err files with contents like

----------------------------------------------------------------------
Beginning MPAS-ocean Error Log File for task     715 of    1396 
    Opened at 2017/05/12 13:09:51
----------------------------------------------------------------------

ERROR:  Warning: abs(sum(h)-bottomDepth)>2m.  Most likely, initial layerThickness does not match bottomDepth.
ERROR:  Warning: abs(sum(h)-bottomDepth)>2m.  Most likely, initial layerThickness does not match bottomDepth.
...

In one run, there were 292 such files.

• why are the files not deleted at the end of the run? ocn.log already logs these warning messages for master proc.
• i was hoping there wouldn't be any scratch files, because they may throttle throughput.

[rljacob]

The default setting in ACME for these log files should be "off" or "root node only" or similar. Just one per model.

[mark-petersen]

@amametjanov, that is not a change due to the log file, it would have printed from every core before. A sea surface height which is more than 2m from zero usually indicates an actual error. Can you point me to the machine (mira?) and directory? I'm out of town, will be slow to respond...

[jonbob]

@mark-petersen - I get those files and warnings every time I restart now. At the very least, should we rename the files to "warn" instead of "err". I thought my run had crashed.

[jonbob]

@mark-petersen - sorry, my bad. I went and double-checked, and I believe I see those files and errors when I start a run from ICG conditions

[amametjanov]

@mark-petersen thanks for the clarification (previously scratch files also had contained similar messages and it wasn't clear whether they were warnings or actual errors).

Run dir on Mira:

• /projects/HiRes_EarthSys_2/azamatm/A_WCYCL2000_H01AS-ne120_oRRS18v3_ICG-2k-20170510/run-01-ok-2048x4x16

[matthewhoffman]

@amametjanov, to clarify, the new log system functionality creates log.CORE.TASK.err files for each processor that experiences an error if and only if an error actually occurs. The model is supposed to abort soon after these files are created. This behavior is similar to the old "critical error" files that no longer exist.

Note that any message written to the head node error file (if it is created) also appears in the ocn.log file. We allow every task to create an error file (if an error on that task occurs), because otherwise it is likely to have a mysterious abort with no associated error log message (if the error did not occur on the master task).

It is possible to configure the MPAS logging system to give these files different names if there is a strong preference to do so.