Fixes to provenance/timing saving

[jgfouca]

1. Timing directory in RUNDIR needs to have lid appended
2. Create timing.$LID.saved
3. Do not include full directory hierarchy in tar files
4. Copy all timing files to performance archive
5. Restore support for mach_syslog
6. In the case timing subdirectory, stop compressing the performance summary file and
   start compressing the raw global statistics timing data.
7. For create_test, if save_timing is false, be sure to set SAVE_TIMING to False

Fixes #1177

[BFB]

[worleyph]

@jgfouca

Timing directory in RUNDIR needs to have lid appended

Check

Create timing.$LID.saved

Check. However, this file is also copied to the performance_archive, and it serves no purpose there. Could you please NOT copy it there?

Do not include full directory hierarchy in tar files

Check

Copy all timing files to performance archive

Check

Restore support for mach_syslog

Not working yet.

One problem is that the current mach_syslog assumes that the model run log is called, cesm.log, not acme.log. This is hardwired. I can change this to be an input parameter, but you will need to add this argument to the call from the run script. I don't know where this is. Where should I look?
Also, does this make sense? I assume that CEMS model runs do not produce an acme.log file, but prehaps CESM does not care to support mach_syslog, in which case there is no reason to add this generality.

Also, the name of the performance_archive checkpoint subdirectory is incorrect. Looking at the output of some instrumentation I added, it looks that $dir is being passed in as checkpoints.$lid/checkpoints , which does not exist. I assume that it should be checkpoints.$lid .

In the case timing subdirectory, stop compressing the performance summary file and
start compressing the raw global statistics timing data.

Check

For create_test, if save_timing is false, be sure to set SAVE_TIMING to False

Someone else will need to test this.

Thanks.

When the above issues are addressed, I'll look at this again, to check more carefully if the current implementation matches that in ACME/CIME2.

[jgfouca]

@worleyph

Could you please NOT copy it there?

Fixed.

... mach_syslog ...

I've fixed the issue with the log names. CESM is not using this, so we can just assume acme logs. I also fixed checkpoint argument. I'm completely unfamiliar with mach_syslog so I have no idea if it's broken in other ways due to the CIME upgrade.

[worleyph]

@jgfouca , thanks. mach_syslog is working now.

A couple of remaining issues (on Titan). I'll test on the other systems once the following are taken care of.

a) Permissions are wrong. All files should be group and world readable, and directories should also be group writable.

For example: CIME2

 -rw-r--r-- 1 worley worley    896 Dec  1 18:51 3096778.OU.161201-183002.gz
 -rw-r--r-- 1 worley worley    525 Dec  1 18:29 build_environment.161201-183002.gz
 drwsrwsr-x 2 worley cli112   4096 Dec  1 18:51 CaseDocs.161201-183002
 -rw-r--r-- 1 worley worley   2502 Dec  1 18:51 CaseStatus.161201-183002.gz
 -rw-r--r-- 1 worley worley 127066 Dec  1 18:51 cesm.log.161201-183002.gz
 -rw-r--r-- 1 worley worley   2172 Dec  1 18:51 cesm_timing.ACME_WCYCL2000.ne30_oEC_pgi_mastercheck_b.161201-183002.gz
 -rw-r--r-- 1 worley worley  18609 Dec  1 18:51 cesm_timing_stats.161201-183002.gz
 drwsrwsr-x 2 worley cli112   4096 Dec  1 18:51 checkpoints

and CIME5

 -rw------- 1 worley cli112   1073 Jan  4 11:13 3160568.OU.170104-105055.gz
 -rw------- 1 worley cli112 265359 Jan  4 11:13 acme.log.170104-105055.gz
 -rw------- 1 worley cli112   2121 Jan  4 11:13 acme_timing.A_WCYCL2000_ne30_oEC_PR1201_pgiacc2.170104-105055.gz
 -rw------- 1 worley cli112  15829 Jan  4 11:13 acme_timing_stats.170104-105055.gz
 -rw------- 1 worley cli112   7536 Jan  4 11:13 build_environment.txt.170104-105055.gz
 drwx--S--- 2 worley cli112   4096 Jan  4 11:14 CaseDocs.170104-105055
 -rw------- 1 worley cli112    164 Jan  4 11:13 CaseStatus.170104-105055.gz
 drwx--S--- 2 worley cli112  24576 Jan  4 13:29 checkpoints.170104-105055
 ...

The same needs to be true in subdirectories as well (i.e. CaseDocs.170104-105055 and heckpoints.170104-105055).

NOTE - having group being cli112 instead of worley is good - thanks for this.

b) Some of the timestamps have been reset??? In mach_syslog, files are copied to the checkpoints subdirectory with '-p', and these timestamps are preserved through subsequent manipulation in CIME2. Something in CIME5 is causing the timestamps to be updated. It is unclear from these experiments whether timestamps are being reset outside of ./checkpoints/ as well (e.g. in the CaseDocs subdirectory) - I'll investigate further if it is not obvious to you. Note that these timestamps provide useful performance and provenance information.

In general, if files are being copied or renamed, could we use '--preserve=timestamps' to keep the timestamps? We should change mach_syslog to use '--preserve=timestamps' also. If you are willing to do this, that will be great. Otherwise I'll try it out once we figure out why timestamps are being changed in the checkpoints subdirectory, as I won't be able to check whether it is doing the right thing until then.

c) Question: The 'top level' has build_environment.txt.$lid.gz . In CaseDocs.$lid there is also a (new) file software_environment.txt.%lid.gz . Are these identical? I know that we will soon be adding run_environment.txt.$lid.gz, but I do not believe that this is in there yet, correct?

[jgfouca]

@worleyph

Permissions are wrong.

OK, I will set the umask at the beginning of the run.

Some of the timestamps have been reset

Ah, this is probably because I'm using shutil.copy instead of cp -p. I can fix.

Question: The 'top level' has build_environment.txt.$lid.gz . In CaseDocs.$lid there is also a (new) file software_environment.txt.%lid.gz . Are these identical? I know that we will soon be adding run_environment.txt.$lid.gz, but I do not believe that this is in there yet, correct?

I think one comes from case.setup and one comes from case.build. run_env is in CIME5.2 but not yet in ACME.

[worleyph]

Note, the performance_archive structure could be improved. Don't want to hold this PR back, and I am not sure what coordination is needed with CESM (if any). At the moment I have added things to CaseDocs that do not appear there in the user's case directory. We should probable have a BuildDocs subdirectory for this extra information, as well as some things currently at the top level like build_environment and GIT_DESCRIBE and SourceMods. We could even have a RunDocs, but that is everything else, so may not add any utility.

[worleyph]

I have no experience with setting umask globally (if that is what your comment meant), but I'm guessing that cp -p might override this, and that you want to use '--preserve=timestamps' instead?

[rljacob]

Is " performance_archive structure could be improved" a new feature? Yes lets save that for a future PR. This PR should get the beta0 version of performance archiving working in cime5 as best as it can.

[worleyph]

@rljacob , yes, sorry to have even brought this up.

[jgfouca]

@worleyph I think I've addressed your concerns

[worleyph]

@jgfouca , the timestamps still are not being preserved in the checkpoints subdirectory. Since many of these are created in the checkpoints directory by mach_syslog, some postprocessing is changing the timestamp? gzip doesn't do this when using /usr/bin/gzip. Are you using a python utlity to compress these? Is there anything else going on with CIME5 and the checkpoints subdirectory?

Thanks.

[jgfouca]

@worleyph yes, I'm using a python gzipper. I'll change it to preserve the timestamp of the original file.

[jgfouca]

@worleyph OK try now. Sorry for the trial-and-error approach we've had to take with this PR; it's hard to test the correctness of this stuff.

[worleyph]

@jgfouca ,

OK try now.

Titan is backed up today ... may take awhile to get runs through. I don't want to start testing on other systems until I verify that everything is working okay on Titan (for my sanity's sake), but I expect everything to work fine this time.

Sorry for the trial-and-error approach we've had to take with this PR; it's hard to test the correctness of this stuff.

I very much appreciate your patience with this process - it is what I expected. I was able to be much more involved, working with Jeff Johnson, for the port to CIME2, but that was not an option this time. The 'fix' to the permissions issue, even though seemingly minor, will remove a major headache going forward. I hope that it works as expected at NERSC, but will verify as soon as I get the chance.

[worleyph]

Everything seems to be working fine on Titan. I'll start trying out the other platforms.

[worleyph]

@jgfouca , testing on cori-haswell, job died with:

 ERROR: Command: 'git describe > /project/projectdirs/acme/performance_archive/worleyph/A_WCYCL2000_ne30_oEC_PR1201_corihaswell3/170110-193504/GIT_DESCRIBE.170110-193504' failed with error 'fatal: Not a git repository (or any parent up to mount point /global/u2/w/worleyph/ACME/jgfouca/cime/perf_data_fixes/ACME/cime)
 Stopping at filesystem boundary (GIT_DISCOVERY_ACROSS_FILESYSTEM not set).' from dir '/global/u2/w/worleyph/ACME/jgfouca/cime/perf_data_fixes/ACME/cime'

[worleyph]

@jgfouca , testing on Edison looks good, except for one minor anomaly. The last files copied into the checkpoint subdirectory in performance_archive were not gzipped. I am guessing that the mach_syslog was not killed until after the files in this subdirectory were gzipped, so a few more copied over. Don't know if the kill was simply delayed, and this was a rare event, or whether the order of operations is different in CIME5 than in CIME2. Since it works on Titan, guess that it is the former, but would like for you to confirm.

[jgfouca]

@worleyph this problem has been fixed by a later branch. The git describe problem I mean.

[worleyph]

@jgfouca , Can I back port this (so that I can test) your branch? What would I look for? (Is this a CIME branch or an ACME branch?)

[jgfouca]

@worleyph I will rebase this branch, just a moment.

[jgfouca]

@worleyph Done.

[worleyph]

@jgfouca , cori-haswell does not create a checkpoints subdirectory (so there is also nothing in it, and can't test mach_syslog until the subdirectory is created).

There are also some other missing items ... sqsw, sqsf, sqsf_jobid, and squeuef .

Thanks.

[worleyph]

Looks like the name change from corip1 to cori-haswell is not in there yet? Perhaps this is would be a second PR, but I'd really like this PR to get everything working on the current target platforms, which include cori-haswell I believe.

[ndkeen]

No, my branch for allowing ACME to run on cori-haswell and cori-knl has not yet made it. I'd prefer to get it in asap, but it was suggested I get all the tests to pass first.

[worleyph]

@amametjanov , I "manually" rebased, and the default PE layout for ne30_oEC and A_WCYCL200 on Cetus requires 4096 nodes. I've tried various things to get a PE layout with 2048 nodes or smaller and nothing has worked so far. All but one failure were obviously memory issues. What compset and resolution and PE layout would you suggest for running on Cetus to test this PR? My Mira job has been in the queu for 8 hours, and others in the same queue with similar resource requests have been there for 5 days, so probably not happening any time soon. Thanks.

[amametjanov]

I just tried with git master and got 1024x1 stacked PE layout on 256 nodes. The issue with 4096 nodes was fixed.

Please try this PE layout for the -compset A_WCYCL2000 -res ne30_oEC -mach cetus case: from here. It uses 16 MPI x 4 OMP per node on 1024 nodes: note the change to PES_PER_NODE=16 in env_mach_pes.xml.

  component       comp_pes    root_pe   tasks  x threads instances (stride) 
  ---------        ------     -------   ------   ------  ---------  ------  
  cpl = cpl        65536       0        16384  x 4       1      (1     )   
  glc = sglc       1           8190     1      x 1       1      (1     )   
  wav = swav       1           8191     1      x 1       1      (1     )   
  lnd = clm        8192        5400     2048   x 4       1      (1     )   
  rof = mosart     2968        7448     742    x 4       1      (1     )   
  ice = mpas-cice  16384       8192     4096   x 4       1      (1     )   
  atm = cam        21600       0        5400   x 4       1      (1     )   
  ocn = mpas-o     16384       12288    4096   x 4       1      (1     )   

    TOT Run Time:     134.442 seconds      134.442 seconds/mday         1.76 myears/wday
    LND Run Time:       1.951 seconds        1.951 seconds/mday       121.33 myears/wday 
    ROF Run Time:       0.866 seconds        0.866 seconds/mday       273.34 myears/wday 
    ICE Run Time:      26.254 seconds       26.254 seconds/mday         9.02 myears/wday 
    ATM Run Time:      94.753 seconds       94.753 seconds/mday         2.50 myears/wday 
    OCN Run Time:      81.347 seconds       81.347 seconds/mday         2.91 myears/wday 
    GLC Run Time:       0.000 seconds        0.000 seconds/mday         0.00 myears/wday 
    WAV Run Time:       0.000 seconds        0.000 seconds/mday         0.00 myears/wday 
    CPL Run Time:       9.996 seconds        9.996 seconds/mday        23.68 myears/wday 
    CPL COMM Time:    122.785 seconds      122.785 seconds/mday         1.93 myears/wday 

A modified env_mach_pes.xml with MPAS in pure-MPI mode is at /home/azamatm/repos/ACME-master/cime/scripts/cases/AWCYCL2000-ne30oEC-1k-testcime5-cetus-04/.

[worleyph]

@amametjanov , thank you. I'm trying an F case at the moment. I thought that I had the latest, but apparently not. I'll try again.

[amametjanov]

Local git rebase can be done with:

$ git checkout master
$ git fetch origin
$ git pull
$ git checkout jgfouca/cime/perf_data_fixes
$ git rebase master
$ git log>gitlog.to_check_the_rebase

[worleyph]

I've rebased and am trying the indicated PE layout (my F case also failed). This layout is the one I started with, but perhaps it failed because of the incorrect manual rebase. I'll report any issues on Slack. Thanks again. I'm hesitant to integrate this PR until I can test that it works on Cetus or Mira.

[worleyph]

@amametjanov , this compset with this PE layout with the rebased version of this PR died on Cetus with

 0: MCT::m_Router::initp_: error, allocate tmpsegcount etc. size =16384,  by =511.
 0: 000.MCT(MPEU)::die.: from MCT::m_Router::initp_()
 0: Abort(2) on node 0 (rank 0 in comm 1140850688): application called MPI_Abort(MPI_COMM_WORLD, 2) - process 0

with the tail of cpl.log

 (prep_ocn_init) : Initializing mapper_Rr2o
 (seq_map_init_rcfile)  called for mapper_Rr2o initialization
 
 (shr_mct_sMatPInitnc) Initializing SparseMatrixPlus
 (shr_mct_sMatPInitnc) SmatP mapname /projects/ccsm/inputdata/cpl/cpl6/map_r05_to_oEC60to30_smoothed.r175e350.160718.nc
 (shr_mct_sMatPInitnc) SmatP maptype Y
 (shr_mct_sMatReaddnc) reading mapping matrix data decomposed...
 (shr_mct_sMatReaddnc) * file name                  : /projects/ccsm/inputdata/cpl/cpl6/map_r05_to_oEC60to30_smoothed.r175e350.160718.nc
 (shr_mct_sMatReaddnc) * matrix dims src x dst      :     259200 x    234988
 (shr_mct_sMatReaddnc) * number of non-zero elements:    9771823
 (shr_mct_sMatReaddnc) ... done reading file

FYI.

[worleyph]

@amametjanov , actually it was not exactly your PE layout. I had to set NTHRDS to 1 for OCN and ICE since compilation had taken over 3 hours last night. I killed it and restarted (without a clean) this morning, and it has been "compiling" for 4 more hours today, and still has nto finished. I gave up and created a new case with the same PE layout without threading in the ocean or sea ice.

[amametjanov]

Pat, here is a PE layout that worked with the latest git master (v1.0.0-beta-196-g2999941): /home/azamatm/repos/ACME-master/cime/scripts/cases/AWCYCL2000-ne30oEC-1k-testcime5-cetus-04/env_mach_pes.xml

  component       comp_pes    root_pe   tasks  x threads instances (stride)
  ---------        ------     -------   ------   ------  ---------  ------  
  cpl = cpl        4096        0        4096   x 16      1      (1     ) 
  glc = sglc       1           2046     1      x 1       1      (1     )   
  wav = swav       1           2047     1      x 1       1      (1     )   
  lnd = clm        512         1350     512    x 16      1      (1     )   
  rof = mosart     184         1862     184    x 16      1      (1     )   
  ice = mpascice   1024        2048     1024   x 1       1      (1     )   
  atm = cam        1350        0        1350   x 16      1      (1     )   
  ocn = mpaso      1024        3072     1024   x 1       1      (1     )   

    TOT Run Time:     747.094 seconds      747.094 seconds/mday         0.32 myears/wday
    LND Run Time:       2.143 seconds        2.143 seconds/mday       110.46 myears/wday
    ROF Run Time:       1.515 seconds        1.515 seconds/mday       156.25 myears/wday 
    ICE Run Time:      39.348 seconds       39.348 seconds/mday         6.02 myears/wday 
    ATM Run Time:     110.804 seconds      110.804 seconds/mday         2.14 myears/wday 
    OCN Run Time:     594.247 seconds      594.247 seconds/mday         0.40 myears/wday 
    GLC Run Time:       0.000 seconds        0.000 seconds/mday         0.00 myears/wday 
    WAV Run Time:       0.000 seconds        0.000 seconds/mday         0.00 myears/wday 
    CPL Run Time:      10.036 seconds       10.036 seconds/mday        23.59 myears/wday 
    CPL COMM Time:    590.317 seconds      590.317 seconds/mday         0.40 myears/wday 

[worleyph]

@amametjanov , this layout failed for me also:

 405: Out of memory in file /bgsys/source/srcV1R2M2.15270/comm/lib/dev/mpich2/src/mpi/romio/adio/ad_bg/ad_bg_rdcoll.c, line 1073
 413: Out of memory in file /bgsys/source/srcV1R2M2.15270/comm/lib/dev/mpich2/src/mpi/romio/adio/ad_bg/ad_bg_rdcoll.c, line 1073
 473: Out of memory in file /bgsys/source/srcV1R2M2.15270/comm/lib/dev/mpich2/src/mpi/romio/adio/ad_bg/ad_bg_rdcoll.c, line 1073
 409: Out of memory in file /bgsys/source/srcV1R2M2.15270/comm/lib/dev/mpich2/src/mpi/romio/adio/ad_bg/ad_bg_rdcoll.c, line 1073
 465: Out of memory in file /bgsys/source/srcV1R2M2.15270/comm/lib/dev/mpich2/src/mpi/romio/adio/ad_bg/ad_bg_rdcoll.c, line 1073
 469: Out of memory in file /bgsys/source/srcV1R2M2.15270/comm/lib/dev/mpich2/src/mpi/romio/adio/ad_bg/ad_bg_rdcoll.c, line 1073

Can you take over testing this PR on Mira or Cetus? I don't know what else to try. There are a few changes that need to be made in user_nl_cpl and env_run.xml to force checkpoints to happen often enough to be tested for a short run, but otherwise this is vanilla. (I did turn off restart writes, the ocean history write at startup, and only set STOP_N to 2 days, simply to make the job relataively short.)

Another option is some other case that is supposed to work. I tried an F case (without success), but this was ne30. Perhaps something smaller?

[worleyph]

Note that I am building with cetus as the target, but this should be identical to using Mira as the target, correct? Can't imagine why this worked for you and not for me.

[ndkeen]

Now I do recognize that error. I get something like:
Out of memory in file /notbackedup/tmp/ulib/mpt_base/mpich2/src/mpi/romio/adio/ad_cray/ad_cray_write_coll.c, line 486
For haswell/KNL runs on Cori. I think this is where adjusting the PIO_STRIDE helped.

[worleyph]

I'll give that a try. Thanks.

[worleyph]

@amametjanov and @ndkeen , Cetus job worked that time. Thanks! I need to rerun again, since I need to modify provenance.py to treat Cetus the same way that Mira is treated in order to exercise all of the functionality, but expect to be able to finish my review this evening.

[worleyph]

@jgfouca and @rljacob , I've successfully tested this PR using A_WCYCL2000 with ne30_oEC on Titan, Edison, Cori-Haswell, and Cetus, and it should also work fine on Mira. I have not tested on Cori-KNL, but am hopeful that it will work there as well, based on the successful runs on Cori-Haswell. We should not wait any longer to integrate this. I'll likely introduce a new PR in the near future to add support for Anvil.

According to @jgfouca , the remaining issues not addressed by this PR will be resolved when CIME 5.2 is merged into ACME.

[ndkeen]

I can test on KNL

[worleyph]

You'll want to:

a) Change SYSLOG_N in env_run.xml to 60 (from 900), so that the monitoring job collects checkpoints every minute instead of every 15 minutes - lets you run shorter jobs and still make sure that things are working.

b) Add the following to user_nl_cpl:

tprof_n = 1
tprof_option = 'ndays'

and also run at least 2 simulated days (with whatever compset you choose).

[jgfouca]

@worleyph if you have machine-specific fixes for this branch, feel free to push them yourself.

If you're going to hold off, go ahead and merge this to next so we can finish this PR off.

[jgfouca]

@worleyph That git describe issue probably means that the environment settings for cori-haswell in the config_machines.xml file are missing git setup.

[worleyph]

@jgfouca ,

@worleyph That git describe issue probably means that the environment settings for cori-haswell in the config_machines.xml file are missing git setup.

You fixed this for me already.

Everything is working fine for me now. As I indicated in my e-mail, I no longer have time to integrate this, and have asked @rljacob (or someone else) to finish this up. I have however finished my testing and review, and think that it is good to go. I prefer not to wait for @ndkeen to test this on cori-knl. If it is broken there, we can deal with this in a different PR.

[jgfouca]

@worleyph sorry, I was slow to catch up on the full conversation. @rljacob please merge to next.

[rljacob]

This has been reviewed by many.