Ideas for better logging

This is a proposal to improve the clarity of logging and overall user experience in GEOSX. I will describe several ideas that can be discussed/accepted/rejected separately.

1. Component log levels. Declare a fixed set of logging levels with well-defined usage guidelines across different components of the code. It remains up to each individual component to define specifically what to output at each level, in accordance with these guidelines. In addition to that, we should introduce a separate flag into physics solvers and/or linear solvers for dumping large-volume debugging information (primarily linear systems) to screen/file, and separate this setting from logLevel. Off the top of my head, I would define at least these 4 log levels:

   • silent: maximum possible silent execution, not even time stepping; not sure if this is useful to anyone in practice, but I like it when command-line programs have a silent mode, it's good for scripting
   • progress (or normal, or default): forward progress information only, such as time steps for EventManager, time step attempts and Newton loop progress for physics solvers
   • detailed: in addition to progress, print more detailed info and stats that affect progress, e.g. residual norms.
   • trace: in addition to all of the above, log a detailed trace of what each component is doing, this would include for example a line for every part of the assembly process, every boundary condition that's being applied by a physics solver, etc. This is intended as a user-level debugging tool.

2. Application-wide log levels. These can be the same or different from the above, but controlled globally via a command-line flag (e.g. --verbosity=trace). This can have two functions:

   • Override component-level log levels, i.e. if the application-wide log level is silent, even components with more verbose log levels shouldn't print anything. This way we could enable high verbosity by default in all of our tests, but a developer running a specific test case where they aren't interested in that level of detail can bring it down a notch without changing the input file.
   • Control logging level for things that are either not attached to a specific component (e.g. printing overall time statistics at the end, version/threads at the beginning, etc.), or where component log level cannot yet apply (e.g. trace of the XML being read - we haven't parsed the logLevel attribute at that point yet).

3. Structured logging. Currently we are rather random in how the logging is structured, e.g. what amount of whitespace is prepended to each line, and logs aren't very grep-friendly because important context (such as current time) is missing from each specific line. The idea is to introduce call-stack-based logging contexts and have them automatically prepended to each log line, to have it looking along the lines of:

[t=1e+6][dt=1e+4][compflow][attempt=1][newton=8] Convergence not reached, going to cut the time step

This would likely take a form similar to annotating scopes with Caliper macros:

for( integer newtonIter = 0; newtonIter < maxNewtonIter; ++newtonIter )
{
  GEOSX_LOG_SCOPE( "newton=" << newtonIter );
  ...
}

I haven't fully developed this idea in my head yet, feel free to disagree (or even immediately hate it) :)

4. Memory transfer logging. This is a very minor point, but I think that logging all host-device memory transfers in CUDA runs should be an option, not the default. It aids the developer, but not very useful for a normal user. We have the command-line flag that disables it, but it should be exactly the other way around.