Logging

[Psirus]

trafficstars

There is quite the diversity in how to log stuff in NuTo:

• some methods write to cout, some to the logger
• some objects use their own verbose level, some use that of the structure
• there is no way of knowing what verboseLevel=3 might mean

Maybe we can collect the requirements here, and discuss how people currently use it, and what they would like to see. E.g. do we need a verbose level for every object, or would one global verbosity level be enough?

Personally, instead of an Info method, I'd prefer an outstream operator, so that I can say std::cout << myElement; and it will print itself.

[TTitscher]

I prefer the iostreams as well. Just a quick note: Whenever possible, use #include <iosfwd> in the header files to reduce compile time...

[Psirus]

The commit 7ab0896 demonstrates the operator<< approach on the sections. Commit e4b7ca1 maps this to the __str__ function in SWIG, so that you can do print(section) instead of calling section.Info() in Python as well.

[TTitscher]

I think, passing the logger around, is quite annoying. How about boost.log?

e.g.

#include <boost/log/trivial.hpp>
...
BOOST_LOG_TRIVIAL(trace) << "A trace severity message";

• Besides the record message, each log record in the output contains a timestamp, the current thread identifier and severity level.
• It is safe to write logs from different threads concurrently, log messages will not be corrupted.
• As will be shown later, filtering can be applied.

[joergfunger]

Another comment - style back to the roots :) This logger was used in the case where FE² type multiscale models are used, i.e. there was a separate structure for each integration point. For each evaluation of a macroscopic stress/stiffness evaluation, the corresponding strain was applied to the boundary of the RVE and then a solve on the fine scale had to be performed - so a very nested procedure. When using a single logger, it was very difficult to distinguish between the iterations/MUMPS solves performed on the global level or the fine scale (with each integration point). As a consequence, this logger was introduced that could store the file to be logged. In this way, it was possible to store information related to different solves (but calling the same solver, e.g. MUMPS) into different files.

[TTitscher]

I found myself adding methods like "SetQuiet()" to classes to suppress std::cout output. But this seems like the job of a logger. So I really like to collect ideas on this issue. Most logging frameworks have IMO very different purposes than our "write time steps / residuals / casual infos". So I thought about a simple solution and came up with global instances of NuTo::Logger.

Like

/* nuto/base/Logger.h */
extern Logger LoggerInfo;
extern Logger LoggerWarning;
// or maybe in a namespace, Logger::Info, Logger::Warning, Logger::Debug, Logger::Total, ...

that are all defined in Logger.cpp. You can now simply include Logger.h (and link Logger.cpp) from everywhere and write to those global objects.

#include <nuto/base/Logger.h>
void Something::DoStep(double t)
{
    Logger::Info << "Solving for t = " << t << ".\n";
    ...

If you want to suppress the output or write to a file, you add

#include <nuto/base/Logger.h>
LoggerInfo.SetQuiet(true);
LoggerWarning.OpenFile("Warnings.log");

to your main file.

pro:

• dead simple
• no new external dependencies, no new libs to link (Boost::log)
• everyone is familiar with the NuTo::Logger
• output visibility is controlled at one point
• no need to pass the logger as a parameter
• if you like, you can still create other logger instances and pass them via parameter

con:

• ??? :ghost:

[TTitscher]

As #240 is merged, do we want to advance it? Some ideas

• [ ] log exceptions to NuTo::Log::Error
  • [ ] with pragma omp critical for thread safety
• [ ] avoid std::cout in codebase and in future PRs, currently used in
  • [ ] geometry concrete
  • [ ] NuTo::Timer --> log NuTo::Log::Info by default