SCREAM log messages appear in e3sm.log instead of atm.log

[PeterCaldwell]

This is tacky and annoying rather than a critical problem...

SCREAM log messages appear in e3sm.log instead of atm.log. @rljacob told me that anything written to stdout is sent to e3sm.log. EAMf90 writes to atm.log by passing its file handle to every function that needs to include output and including that file handle in each write command. This would be a hassle to implement in SCREAM but I'm not sure if just redirecting everything sent to stdout to atm.log during SCREAM calls would be acceptable...

[AaronDonahue]

A detailed list of tasks to address this are in #1372

[AaronDonahue]

More on that, I recall @bartgol or @jeff-cohere mentioning an EKAT routine for printing "to screen" that would allow us to control which file it goes too. In this case, the atm.log file. My understanding is that we can gather the F90 unit id for output from the shared modules and that will alllow us to direct output to atm.log.

The question is, how to we get EAMxx in cpp to use the F90 output unit?

[jeff-cohere]

C/C++ and Fortran use incompatible I/O systems. Usually, the Fortran runtime calls C stuff under the hood (using file descriptors), but I'm not aware of any way for a C/C++ program/library to interpret a Fortran unit number.

[AaronDonahue]

@jeff-cohere , that's what I was afraid of. Can cpp open a file that is already open in F90? I think we should be able to get the atm.log name from the shared modules. Are piece it together in some way.

Alternatively we may need to write a F90 output that we bridge to from cpp. This might be the most consistent way to handle log output.

[jeff-cohere]

I prefer the bridge alternative, since it keeps I/O in a single language and access via a single point. To be clear: you're saying the F90 would call functions to write its data using C++ I/O, right?

[AaronDonahue]

https://github.com/E3SM-Project/scream/blob/master/components/eam/src/control/cam_logfile.F90#L27

https://github.com/E3SM-Project/scream/blob/master/components/eam/src/cpl/atm_comp_mct.F90#L196

So it looks like EAM sets a default unit and then updates it during mct_coupling.

[AaronDonahue]

I prefer the bridge alternative, since it keeps I/O in a single language and access via a single point. To be clear: you're saying the F90 would call functions to write its data using C++ I/O, right?

No, I mean the opposite. That we would have an F90 routine for writing that is called by the cpp code. Since E3SM sets up the IO in F90 to begin with. I believe that the F90 MCT code opens the atm.log file and assigns it a unit. So we would have to either ignore what MCT is doing or circumvent it if we wanted cpp to handle the log output. @rljacob can correct me if I'm wrong about where atm.log is defined.

[jeff-cohere]

Ah. Gross. But I suppose if that's the way E3SM does things, that's probably the way we should proceed.

[AaronDonahue]

now, to be fair, we are only talking about log messages. Not the rest of IO. So it should be a pretty light F90 code and bridge.

[PeterCaldwell]

Rob suggested that we could create our own scream.log file and redirect all our output to that as a temporary solution (if I understand correctly). I guess we could try to close atm.log created by MCT, then overwrite it with a file of the same name written from C++ to get the right name via the same lazy approach...

[PeterCaldwell]

Also, apologies for not noticing that this was already tagged as an issue in #1372. Creating multiple git issues for the same thing is an especially bad faux pas...

[rljacob]

Hang on. E3SM just provides the name of the file for EAM to open. It's basically componenttype.log.jobid-date. It does not open it or create a unit number to hand to EAM.

EAMxx should, using C++ file i/o, open a file and write all its log messages to it. Yes that means you have to find every write message and change it from stdout to a file which is tedious but you only have to do it once. You can worry about getting the correct file name later.

[AaronDonahue]

Hang on. E3SM just provides the name of the file for EAM to open. It's basically componenttype.log.jobid-date. It does not open it or create a unit number to hand to EAM.

EAMxx should, using C++ file i/o, open a file and write all its log messages to it. Yes that means you have to find every write message and change it from stdout to a file which is tedious but you only have to do it once. You can worry about getting the correct file name later.

Okay, that should make things easier. @rljacob , do you know how and where that information is passed? I'll also note that in our current EAMxx simulations the atm.log file is created, but only one log is written there, from some p3 F90 code in the eam directory that we still call at init. So The issue is not that we are not making the file, somehow that is still happening. We just are not writing to it.

[rljacob]

The atm_modelio.nml file in the rundir, created by cime, has the name of the logfile. EAM reads that in atm_init_mct so maybe that's also being called in your init?

[AaronDonahue]

@rljacob , excellent, I see where that happens in our MCT interface now. So based on this it looks like we should be able to create our own interface to write log output in cpp. @jeff-cohere - does such an interface already exist in say EKAT?

[jeff-cohere]

Yup, EKAT comes with spdlog (a fancy C++ logging library) plus its own logging support.

[AaronDonahue]

thats great, so it seems like the infrastructure is there. This is where we do anything with the log file https://github.com/E3SM-Project/scream/blob/master/components/scream/src/mct_coupling/atm_comp_mct.F90#L114

We will need to pass the logfile name to EKAT to open the file and go through the code to have anything that should be in atm.log use the spdlog command.

[AaronDonahue]

@jeff-cohere . thanks for the heads up on logging. I've taken a look at the ekat::logger class, which presumably is the ekat wrapper of spdlog that we will want to use. Looking at the constructor for the logger class it looks like we can't control the name exactly, see:

  // primary constructor
  Logger(const std::string& log_name, const Log::level::level_enum lev,
    const ekat::Comm& comm) :
    spdlog::logger(name_with_rank(log_name, comm)),
    logfile_name_( (LogFilePolicy::has_filename ?
      name_with_rank(log_name, comm) + "_logfile.txt" : "null") )
  {...

From this I understand that we can pass a name, but it will always have _logfile.txt added to the end. In the short run I don't think this will be an issue. I'm just trying to get my head wrapped around the path forward. If this is true then my question is, would it make sense (and be possible) to allow the user to explicitly pass a filename to the logger without "logfile" appended? Mainly I ask because E3SM log files follow a specific pattern, which I believe we want to continue in EAMxx.

Note, the previous chunk of code comes from externals/ekat/src/ekat/logging/ekat_logger.hpp

[jeff-cohere]

I think we can add an additional constructor to the Logger class that allows the log file name to be explicitly set. I'll create an issue in the EKAT repo for that.

EDIT: See EKAT issue 209