Skip to content

Commit 549019c

Browse files
committed
Merge pull request #146 from torbjoernk/feature/rewamp-logging
LGTM
2 parents 8792d7b + 5c772d9 commit 549019c

File tree

8 files changed

+171
-77
lines changed

8 files changed

+171
-77
lines changed

examples/advection_diffusion/advection_diffusion_sweeper.hpp

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -99,7 +99,7 @@ namespace pfasst
9999

100100
virtual ~AdvectionDiffusionSweeper()
101101
{
102-
LOG(INFO) << "number of f1 evals: " << this->nf1evals;
102+
CLOG(INFO, "Advec") << "number of f1 evals: " << this->nf1evals;
103103
}
104104
//! @}
105105

@@ -141,7 +141,7 @@ namespace pfasst
141141

142142
auto n = this->get_controller()->get_step();
143143
auto k = this->get_controller()->get_iteration();
144-
LOG(INFO) << "err: " << n << " " << k << " " << max << " (" << qend.size() << "," << predict << ")";
144+
CLOG(INFO, "Advec") << "err: " << n << " " << k << " " << max << " (" << qend.size() << "," << predict << ")";
145145

146146
this->errors.insert(vtype(ktype(n, k), max));
147147
}
@@ -163,7 +163,7 @@ namespace pfasst
163163

164164
auto n = this->get_controller()->get_step();
165165
auto k = this->get_controller()->get_iteration();
166-
LOG(INFO) << "res: " << n << " " << k << " " << rmax << " (" << residuals.size() << ")";
166+
CLOG(INFO, "Advec") << "res: " << n << " " << k << " " << rmax << " (" << residuals.size() << ")";
167167

168168
this->residuals[ktype(n, k)] = rmax;
169169
}

examples/advection_diffusion/serial_mlsdc.cpp

Lines changed: 12 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,8 @@ using namespace std;
1010
#include <fftw3.h>
1111

1212
#include <pfasst.hpp>
13+
#include <pfasst/logging.hpp>
14+
#include <pfasst/config.hpp>
1315
#include <pfasst/mlsdc.hpp>
1416
#include <pfasst/encap/vector.hpp>
1517
using namespace pfasst::encap;
@@ -28,14 +30,14 @@ namespace pfasst
2830
{
2931
MLSDC<> mlsdc;
3032

31-
const size_t nsteps = 4;
32-
const double dt = 0.01;
33-
const size_t niters = 8;
33+
const size_t nsteps = config::get_value<size_t>("num_steps", 4);
34+
const double dt = config::get_value<double>("delta_step", 0.01);
35+
const size_t niters = config::get_value<size_t>("num_iter", 8);
3436
const int xrat = 2;
3537
const int trat = 2;
3638

37-
size_t nnodes = 5;
38-
size_t ndofs = 128;
39+
size_t nnodes = config::get_value<size_t>("num_nodes", 5);
40+
size_t ndofs = config::get_value<size_t>("spatial_dofs", 128);
3941

4042
/*
4143
* build space/time discretisation levels and add them to mlsdc
@@ -93,8 +95,12 @@ namespace pfasst
9395
} // ::pfasst
9496

9597
#ifndef PFASST_UNIT_TESTING
96-
int main(int /*argc*/, char** /*argv*/)
98+
int main(int argc, char** argv)
9799
{
100+
pfasst::examples::advection_diffusion::AdvectionDiffusionSweeper<>::enable_config_options();
101+
pfasst::init(argc, argv);
102+
pfasst::log::add_custom_logger("Advec");
103+
98104
pfasst::examples::advection_diffusion::run_serial_mlsdc(3);
99105
}
100106
#endif

examples/advection_diffusion/serial_mlsdc_autobuild.cpp

Lines changed: 73 additions & 44 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,8 @@ using namespace std;
1717
#include <fftw3.h>
1818

1919
#include <pfasst.hpp>
20+
#include <pfasst/logging.hpp>
21+
#include <pfasst/config.hpp>
2022
#include <pfasst/mlsdc.hpp>
2123
#include <pfasst/encap/automagic.hpp>
2224
#include <pfasst/encap/vector.hpp>
@@ -29,49 +31,76 @@ using pfasst::examples::advection_diffusion::AdvectionDiffusionSweeper;
2931
using pfasst::examples::advection_diffusion::SpectralTransfer1D;
3032

3133

32-
int main(int /*argc*/, char** /*argv*/)
34+
namespace pfasst
3335
{
34-
MLSDC<> mlsdc;
35-
36-
const size_t nsteps = 4;
37-
const double dt = 0.01;
38-
const size_t niters = 4;
39-
40-
vector<pair<size_t, pfasst::quadrature::QuadratureType>> nodes = {
41-
{ 3, pfasst::quadrature::QuadratureType::GaussLobatto },
42-
{ 5, pfasst::quadrature::QuadratureType::GaussLobatto }
43-
};
44-
45-
vector<size_t> ndofs = { 64, 128 };
46-
47-
/*
48-
* the 'build' function is called once for each level, and returns a
49-
* tuple containing a sweeper, encapsulation factory, and transfer
50-
* routines. in this case our builder is a lambda function that
51-
* captures the 'ndofs' variable from above.
52-
*/
53-
auto build_level = [ndofs](size_t level) {
54-
auto factory = make_shared<VectorFactory<double>>(ndofs[level]);
55-
auto sweeper = make_shared<AdvectionDiffusionSweeper<>>(ndofs[level]);
56-
auto transfer = make_shared<SpectralTransfer1D<>>();
57-
58-
return AutoBuildTuple<>(sweeper, transfer, factory);
59-
};
60-
61-
/*
62-
* the 'initial' function is called once for each level to set the
63-
* intial conditions.
64-
*/
65-
auto initial = [](shared_ptr<EncapSweeper<>> sweeper, shared_ptr<Encapsulation<>> q0) {
66-
auto ad = dynamic_pointer_cast<AdvectionDiffusionSweeper<>>(sweeper);
67-
assert(ad);
68-
ad->exact(q0, 0.0);
69-
};
70-
71-
auto_build(mlsdc, nodes, build_level);
72-
auto_setup(mlsdc, initial);
73-
mlsdc.set_duration(0.0, nsteps*dt, dt, niters);
74-
mlsdc.run();
75-
76-
fftw_cleanup();
36+
namespace examples
37+
{
38+
namespace advection_diffusion
39+
{
40+
tuple<error_map, residual_map> run_serial_mlsdc_autobuild()
41+
{
42+
MLSDC<> mlsdc;
43+
44+
const size_t nsteps = config::get_value<size_t>("num_steps", 4);
45+
const double dt = config::get_value<double>("delta_step", 0.01);
46+
const size_t niters = config::get_value<size_t>("num_iter", 4);
47+
48+
vector<pair<size_t, pfasst::quadrature::QuadratureType>> nodes = {
49+
{ 3, pfasst::quadrature::QuadratureType::GaussLobatto },
50+
{ 5, pfasst::quadrature::QuadratureType::GaussLobatto }
51+
};
52+
53+
vector<size_t> ndofs = { 64, 128 };
54+
55+
/*
56+
* the 'build' function is called once for each level, and returns a
57+
* tuple containing a sweeper, encapsulation factory, and transfer
58+
* routines. in this case our builder is a lambda function that
59+
* captures the 'ndofs' variable from above.
60+
*/
61+
auto build_level = [ndofs](size_t level) {
62+
auto factory = make_shared<VectorFactory<double>>(ndofs[level]);
63+
auto sweeper = make_shared<AdvectionDiffusionSweeper<>>(ndofs[level]);
64+
auto transfer = make_shared<SpectralTransfer1D<>>();
65+
66+
return AutoBuildTuple<>(sweeper, transfer, factory);
67+
};
68+
69+
/*
70+
* the 'initial' function is called once for each level to set the
71+
* intial conditions.
72+
*/
73+
auto initial = [](shared_ptr<EncapSweeper<>> sweeper, shared_ptr<Encapsulation<>> q0) {
74+
auto ad = dynamic_pointer_cast<AdvectionDiffusionSweeper<>>(sweeper);
75+
assert(ad);
76+
ad->exact(q0, 0.0);
77+
};
78+
79+
auto_build(mlsdc, nodes, build_level);
80+
auto_setup(mlsdc, initial);
81+
mlsdc.set_duration(0.0, nsteps*dt, dt, niters);
82+
mlsdc.run();
83+
84+
fftw_cleanup();
85+
86+
tuple<error_map, residual_map> rinfo;
87+
get<0>(rinfo) = mlsdc.get_finest<AdvectionDiffusionSweeper<>>()->get_errors();
88+
for (auto l = mlsdc.coarsest(); l <= mlsdc.finest(); ++l) {
89+
get<1>(rinfo).insert(pair<size_t, error_map>(l.level, l.current<AdvectionDiffusionSweeper<>>()->get_residuals()));
90+
}
91+
return rinfo;
92+
}
93+
} // ::pfasst::examples::advection_diffusion
94+
} // ::pfasst::examples
95+
} // ::pfasst
96+
97+
#ifndef PFASST_UNIT_TESTING
98+
int main(int argc, char** argv)
99+
{
100+
pfasst::examples::advection_diffusion::AdvectionDiffusionSweeper<>::enable_config_options();
101+
pfasst::init(argc, argv);
102+
pfasst::log::add_custom_logger("Advec");
103+
104+
pfasst::examples::advection_diffusion::run_serial_mlsdc_autobuild();
77105
}
106+
#endif

examples/advection_diffusion/vanilla_sdc.cpp

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -66,6 +66,7 @@ int main(int argc, char** argv)
6666
{
6767
pfasst::examples::advection_diffusion::AdvectionDiffusionSweeper<>::enable_config_options();
6868
pfasst::init(argc, argv);
69+
pfasst::log::add_custom_logger("Advec");
6970

7071
pfasst::examples::advection_diffusion::run_vanilla_sdc(0.0);
7172
}

include/pfasst/encap/imex_sweeper.hpp

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@
88
#include <memory>
99

1010
#include "../globals.hpp"
11+
#include "../logging.hpp"
1112
#include "../quadrature.hpp"
1213
#include "encapsulation.hpp"
1314
#include "encap_sweeper.hpp"
@@ -292,6 +293,8 @@ namespace pfasst
292293
{
293294
time dt = this->get_controller()->get_time_step();
294295
time t = this->get_controller()->get_time();
296+
CLOG(INFO, "Sweeper") << "predicting step " << this->get_controller()->get_step() + 1
297+
<< " (t=" << t << ", dt=" << dt << ")";
295298

296299
if (initial) {
297300
this->state[0]->copy(this->start_state);
@@ -319,6 +322,8 @@ namespace pfasst
319322
UNUSED(initial);
320323
time dt = this->get_controller()->get_time_step();
321324
time t = this->get_controller()->get_time();
325+
CLOG(INFO, "Sweeper") << "predicting step " << this->get_controller()->get_step() + 1
326+
<< " (t=" << t << ", dt=" << dt << ")";
322327
time ds;
323328

324329
shared_ptr<Encapsulation<time>> rhs = this->get_factory()->create(pfasst::encap::solution);
@@ -349,6 +354,8 @@ namespace pfasst
349354
auto const nodes = this->quadrature->get_nodes();
350355
auto const dt = this->get_controller()->get_time_step();
351356
auto const s_mat = this->quadrature->get_s_mat().block(1, 0, nodes.size()-1, nodes.size());
357+
CLOG(INFO, "Sweeper") << "sweeping on step " << this->get_controller()->get_step() + 1
358+
<< " in iteration " << this->get_controller()->get_iteration() << " (dt=" << dt << ")";
352359
time ds;
353360

354361
this->s_integrals[0]->mat_apply(this->s_integrals, dt, s_mat, this->fs_expl, true);
@@ -384,6 +391,8 @@ namespace pfasst
384391
auto const nodes = this->quadrature->get_nodes();
385392
auto const dt = this->get_controller()->get_time_step();
386393
auto const s_mat = this->quadrature->get_s_mat();
394+
CLOG(INFO, "Sweeper") << "sweeping on step " << this->get_controller()->get_step() + 1
395+
<< " in iteration " << this->get_controller()->get_iteration() << " (dt=" << dt << ")";
387396
time ds;
388397

389398
this->s_integrals[0]->mat_apply(this->s_integrals, dt, s_mat, this->fs_expl, true);

include/pfasst/logging.hpp

Lines changed: 67 additions & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,8 @@
66
#include <string>
77
using namespace std;
88

9+
#include <boost/algorithm/string.hpp>
10+
911
struct OUT
1012
{
1113
public:
@@ -97,6 +99,8 @@ const string OUT::reset = "\033[0m";
9799

98100
#define LOG_INDENT string(pfasst::log::stack_position * 2, ' ')
99101

102+
//! length of logger ID to print
103+
#define LOGGER_ID_LENGTH 8
100104

101105
namespace pfasst
102106
{
@@ -120,43 +124,82 @@ namespace pfasst
120124
static size_t stack_position;
121125

122126
/**
123-
* sets default configuration for default loggers
127+
* \brief provides convenient way of adding additional named loggers
128+
* \details With this function one can easily create additional named loggers distinctable by the `id`.
129+
* The first \ref LOGGER_ID_LENGTH characters of the ID (as uppercase) will be included in every line of the log.
130+
* The ID is used in the actual logging calls.
131+
*
132+
* \code{.cpp}
133+
* add_custom_logger("MyCustomLogger")
134+
* // somewhere else in the code
135+
* CLOG(INFO, "MyCustomLogger") << "a logging message";
136+
* \endcode
137+
*
138+
* This results in the log line (for the default value of \ref LOGGER_ID_LENGTH):
139+
*
140+
* <TIME> [MYCUSTOM, INFO ] a logging message
141+
* \note Please make sure to use `CLOG` (and `CVLOG` for verbose logging) to be able to specify a specific logger.
142+
* Otherwise the default logger will be used.
143+
* \param[in] id The ID of the logger. This is used in logging calls.
124144
*/
125-
inline static void load_default_config()
145+
inline static void add_custom_logger(const string& id)
126146
{
127147
const string TIMESTAMP = OUT::white + "%datetime{%H:%m:%s,%g}" + OUT::reset + " ";
128-
const string LEVEL = "[%level]";
129-
const string VLEVEL = "[VERB%vlevel]";
148+
const string LEVEL = "%level]";
149+
const string VLEVEL = "VERB%vlevel]";
130150
const string POSITION = "%fbase:%line";
131151
const string MESSAGE = "%msg";
132152

153+
const string INFO_COLOR = OUT::blue;
154+
const string DEBG_COLOR = "";
155+
const string WARN_COLOR = OUT::magenta;
156+
const string ERRO_COLOR = OUT::red;
157+
const string FATA_COLOR = OUT::red + OUT::bold;
158+
const string VERB_COLOR = OUT::white;
159+
160+
const size_t id_length = id.size();
161+
string id2print = id.substr(0, LOGGER_ID_LENGTH);
162+
boost::to_upper(id2print);
163+
if (id_length < LOGGER_ID_LENGTH) {
164+
id2print.append(LOGGER_ID_LENGTH - id_length, ' ');
165+
}
166+
167+
el::Logger* logger = el::Loggers::getLogger(id);
168+
el::Configurations* conf = logger->configurations();
169+
conf->set(el::Level::Info, el::ConfigurationType::Format,
170+
TIMESTAMP + INFO_COLOR + "[" + id2print + ", " + LEVEL + " " + MESSAGE + OUT::reset);
171+
conf->set(el::Level::Debug, el::ConfigurationType::Format,
172+
TIMESTAMP + DEBG_COLOR + "[" + id2print + ", " + LEVEL + " " + POSITION + " " + MESSAGE + OUT::reset);
173+
conf->set(el::Level::Warning, el::ConfigurationType::Format,
174+
TIMESTAMP + WARN_COLOR + "[" + id2print + ", " + LEVEL + " " + MESSAGE + OUT::reset);
175+
conf->set(el::Level::Error, el::ConfigurationType::Format,
176+
TIMESTAMP + ERRO_COLOR + "[" + id2print + ", " + LEVEL + " " + MESSAGE + OUT::reset);
177+
conf->set(el::Level::Fatal, el::ConfigurationType::Format,
178+
TIMESTAMP + FATA_COLOR + "[" + id2print + ", " + LEVEL + " " + POSITION + " " + MESSAGE + OUT::reset);
179+
conf->set(el::Level::Verbose, el::ConfigurationType::Format,
180+
TIMESTAMP + VERB_COLOR + "[" + id2print + ", " + VLEVEL + " " + MESSAGE + OUT::reset);
181+
el::Loggers::reconfigureLogger(logger, *conf);
182+
}
183+
184+
/**
185+
* sets default configuration for default loggers
186+
*/
187+
inline static void load_default_config()
188+
{
133189
el::Configurations defaultConf;
134190
defaultConf.setToDefault();
135191

136-
defaultConf.setGlobally(el::ConfigurationType::Format, "%msg");
137192
defaultConf.setGlobally(el::ConfigurationType::ToFile, "false");
138193
defaultConf.setGlobally(el::ConfigurationType::ToStandardOutput, "true");
139194
defaultConf.setGlobally(el::ConfigurationType::MillisecondsWidth, PFASST_LOGGER_DEFAULT_GLOBAL_MILLISECOND_WIDTH);
140-
141-
defaultConf.set(el::Level::Info, el::ConfigurationType::Format,
142-
TIMESTAMP + OUT::blue + LEVEL + " " + MESSAGE + OUT::reset);
143-
144-
defaultConf.set(el::Level::Debug, el::ConfigurationType::Format,
145-
TIMESTAMP + LEVEL + " " + POSITION + " " + MESSAGE + OUT::reset);
146-
147-
defaultConf.set(el::Level::Warning, el::ConfigurationType::Format,
148-
TIMESTAMP + OUT::magenta + LEVEL + " " + MESSAGE + OUT::reset);
149-
150-
defaultConf.set(el::Level::Error, el::ConfigurationType::Format,
151-
TIMESTAMP + OUT::red + LEVEL + " " + MESSAGE + OUT::reset);
152-
153-
defaultConf.set(el::Level::Fatal, el::ConfigurationType::Format,
154-
TIMESTAMP + OUT::red + OUT::bold + LEVEL + " " + POSITION + " " + MESSAGE + OUT::reset);
155-
156-
defaultConf.set(el::Level::Verbose, el::ConfigurationType::Format,
157-
TIMESTAMP + OUT::white + VLEVEL + " " + MESSAGE + OUT::reset);
158-
159195
el::Loggers::reconfigureAllLoggers(defaultConf);
196+
197+
add_custom_logger("default");
198+
add_custom_logger("Controller");
199+
add_custom_logger("Sweeper");
200+
add_custom_logger("Encap");
201+
add_custom_logger("Quadrature");
202+
add_custom_logger("User");
160203
}
161204

162205
/**

0 commit comments

Comments
 (0)