Skip to content

Commit e29a916

Browse files
authored
Merge pull request #222 from thelfer/219-enable-profiling-via-context
Add profiling support via Context.
2 parents 8516411 + 26a10fa commit e29a916

10 files changed

Lines changed: 522 additions & 8 deletions

File tree

docs/web/profiling.md

Lines changed: 112 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,112 @@
1+
---
2+
title: Profiling system in `MGIS`
3+
author: Julien Rigal, Thomas Helfer
4+
date: 2026
5+
lang: en-EN
6+
numbersections: true
7+
documentclass: article
8+
from: markdown+tex_math_single_backslash
9+
geometry:
10+
- margin=2cm
11+
papersize: a4
12+
link-citations: true
13+
colorlinks: true
14+
figPrefixTemplate: "$$i$$"
15+
tabPrefixTemplate: "$$i$$"
16+
secPrefixTemplate: "$$i$$"
17+
eqnPrefixTemplate: "($$i$$)"
18+
bibliography: bibliography.bib
19+
---
20+
21+
This section describes the profiling system introduced in `MGIS`, which is meant to:
22+
23+
1. provide a hierarchical and precise measurement of execution times across the library.
24+
2. ensure minimal to zero overhead when disabled, preserving the high-performance computing requirements of the code.
25+
26+
By tying the profiling system directly to the `Context` object, `MGIS` avoids the need to pass an additional profiler object through the call stack. A function using this profiling strategy is recognizable by the presence of a `Context` object and the use of dedicated profiling macros.
27+
28+
# The `ProfilingData` structure
29+
30+
The result of the profiling is not a flat list of timers, but a hierarchical tree. Each node in this tree is represented by the `ProfilingData` structure, which stores:
31+
32+
- `name`: A `std::string` representing the name of the profiled section.
33+
- `time_in_seconds`: A `double` accumulating the total time spent in this section.
34+
- `calls`: An `unsigned int` counting the number of times this section was executed.
35+
- `children`: A `std::vector` of `std::shared_ptr<ProfilingData>`, representing the nested profiled sections called within the current one.
36+
37+
# Managing the Profiling State
38+
39+
The profiling system is disabled by default to guarantee zero overhead in production runs. It can be dynamically controlled through the `Context` object using the following methods:
40+
41+
- `enableProfiling(bool)`: Turns the global profiling on or off for the given context.
42+
- `isProfilingEnabled()`: Returns a boolean indicating the current state of the profiler.
43+
- `getProfilingResultTree()`: Retrieves the root node of the profiling tree (`ProfilingData`) containing all the collected metrics.
44+
45+
# Instrumenting the code
46+
47+
The profiling relies on the **RAII** (Resource Acquisition Is Initialization) idiom. Instead of manually starting and stopping timers, the developer creates a scoped object that starts a timer upon construction and stops it, while updating the tree, upon destruction.
48+
49+
To ensure high readability and ease of use, this mechanism is wrapped in macros.
50+
51+
## The `CatchTimeSection` macro
52+
53+
The `CatchTimeSection` macro is the standard way to profile a block of code. It takes two arguments:
54+
1. The `Context` object.
55+
2. A string literal representing the name of the section.
56+
57+
If profiling is enabled in the provided `Context`, the macro will automatically find its place in the hierarchical tree, start the timer, and record the elapsed time at the end of the current scope. If profiling is disabled, the macro does nothing.
58+
59+
## The `CatchLocalTimeSection` macro
60+
61+
In some specific debugging scenarios, a developer might want to force the profiling of a specific section even if the global profiling state is disabled. The `CatchLocalTimeSection` macro takes a third boolean argument:
62+
63+
~~~~{.cxx}
64+
// The third argument 'true' forces the profiling of this specific scope
65+
CatchLocalTimeSection(ctx, "ForcedSection", true);
66+
~~~~
67+
68+
# Aggregation and Loops
69+
70+
To prevent the profiling tree from growing indefinitely and consuming too much memory, the system automatically aggregates repeated calls to the same section within the same parent scope.
71+
72+
If a profiled section is called multiple times (for example, inside a `for` or `while` loop), the profiler does not create a new child node for each iteration. Instead, it finds the existing child node with the same name, increments its `calls` counter, and adds the elapsed time to `time_in_seconds`.
73+
74+
# Example of usage
75+
76+
The following code illustrates how to instrument a function and how the tree hierarchy and loop aggregation behave:
77+
78+
~~~~{.cxx}
79+
void performComputation(mgis::Context& ctx)
80+
{
81+
ctx.enableProfiling(true);
82+
83+
// Start a root section
84+
{
85+
CatchTimeSection(ctx, "IntegrationStep");
86+
87+
// Nested section
88+
{
89+
CatchTimeSection(ctx, "Initialization");
90+
// ... initialization code ...
91+
}
92+
93+
// Loop with a nested section
94+
for (int i = 0; i < 1000; ++i) {
95+
CatchTimeSection(ctx, "NewtonRaphsonIteration");
96+
// ... solver code ...
97+
}
98+
}
99+
100+
// Retrieve and analyze the results
101+
const auto& root = ctx.getProfilingResultTree();
102+
// 'root' contains 1 child: "IntegrationStep"
103+
// "IntegrationStep" contains 2 children: "Initialization" and "NewtonRaphsonIteration"
104+
// "NewtonRaphsonIteration" will show: calls = 1000
105+
}
106+
~~~~
107+
108+
In this example, despite the `NewtonRaphsonIteration` section being timed 1000 times, only one node is created in the tree under `IntegrationStep`, with its `calls` attribute set to `1000` and its `time_in_seconds` representing the total time spent across all iterations.
109+
110+
> **Note**
111+
>
112+
> Exhaustive examples and unit tests of the profiling system, including edge cases, can be found in the `tests/ProfilingTest.cxx` file.

include/CMakeLists.txt

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,8 @@ mgis_header(MGIS Contract.hxx)
77
mgis_header(MGIS Contract.ixx)
88
mgis_header(MGIS Context.hxx)
99
mgis_header(MGIS Context.ixx)
10+
mgis_header(MGIS ProfilingData.hxx)
11+
mgis_header(MGIS Profiling.hxx)
1012
mgis_header(MGIS ErrorBacktrace.hxx)
1113
mgis_header(MGIS InvalidResult.hxx)
1214
mgis_header(MGIS InvalidResult.ixx)

include/MGIS/Context.hxx

Lines changed: 91 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -10,11 +10,14 @@
1010
#include <memory>
1111
#include <variant>
1212
#include <ostream>
13+
#include <vector>
1314
#include "MGIS/Config.hxx"
1415
#include "MGIS/Raise.hxx"
1516
#include "MGIS/LogStream.hxx"
1617
#include "MGIS/VerbosityLevel.hxx"
1718
#include "MGIS/ErrorBacktrace.hxx"
19+
#include "MGIS/ProfilingData.hxx"
20+
#include "MGIS/Profiling.hxx"
1821

1922
namespace mgis {
2023

@@ -29,7 +32,7 @@ namespace mgis {
2932

3033
/*!
3134
* \brief a class used to pass an execution context to most methods of
32-
* `MGIS` and gather information (error, logs).
35+
* `MGIS` and gather information (error, logs, profiling).
3336
*
3437
* The default logging stream is the one returned by the
3538
* `mgis::getDefaultLogStream` free function.
@@ -71,13 +74,15 @@ namespace mgis {
7174
//! \brief reference to the context that created the failure handler
7275
Context &ctx;
7376
};
77+
7478
/*!
7579
* \brief default constructor
7680
*
7781
* The verbositiy level is initialized by calling the
7882
* `getDefaultVerbosityLevel` function.
7983
*/
8084
Context() noexcept;
85+
8186
/*!
8287
* \brief constructor for an initializer
8388
* \param[in] i: initializer
@@ -90,11 +95,65 @@ namespace mgis {
9095
Context &operator=(const Context &) = delete;
9196
//! \return the verbosity level
9297
[[nodiscard]] const VerbosityLevel &getVerbosityLevel() const noexcept;
98+
9399
/*!
94100
* \brief change the level of verbosity
95101
* \param[in] l: the new verbose level
96102
*/
97103
void setVerbosityLevel(const VerbosityLevel) noexcept;
104+
105+
/*!
106+
* \brief enable or disable profiling
107+
* \param[in] b: a boolean value stating whether profiling shall be enabled
108+
*
109+
* \note when profiling is disabled, profiling sections introduce
110+
* almost no overhead.
111+
*/
112+
void enableProfiling(const bool) noexcept;
113+
114+
/*!
115+
* \return true if profiling is enabled, false otherwise
116+
*/
117+
[[nodiscard]] bool isProfilingEnabled() const noexcept;
118+
119+
/*!
120+
* \brief start a new profiling section
121+
* \param[in] name: name of the profiling section
122+
* \param[in] enabled: boolean stating whether this profiling section
123+
* shall effectively collect timing information
124+
*
125+
* \return a profiling section object
126+
*
127+
* \note the returned object relies on RAII semantics:
128+
* timing starts during construction and stops during destruction.
129+
*/
130+
[[nodiscard]] ProfilingSection startNewProfiling(
131+
std::string,
132+
bool) noexcept;
133+
134+
/*!
135+
* \brief push a new profiling node into the current execution stack
136+
* \param[in] name: name of the profiling section
137+
*
138+
* \note this method is meant to be called internally by the
139+
* `Profiling` class during its construction.
140+
*/
141+
void pushProfilingNode(std::string) noexcept;
142+
143+
/*!
144+
* \brief pop the current profiling node from the execution stack and accumulate time
145+
* \param[in] dt: execution time of the section in seconds
146+
*
147+
* \note this method is meant to be called internally by the
148+
* `Profiling` class during its destruction.
149+
*/
150+
void popProfilingNode(double) noexcept;
151+
152+
/*!
153+
* \return the root node of the profiling results tree gathered during execution
154+
*/
155+
[[nodiscard]] const ProfilingData& getProfilingResultTree() const noexcept;
156+
98157
/*!
99158
* \return a failure handler
100159
* \tparam policy: policy used to treat a failure
@@ -104,18 +163,22 @@ namespace mgis {
104163
[[nodiscard]] FailureHandler<policy> getFailureHandler() {
105164
return FailureHandler<policy>{*this};
106165
}
166+
107167
//! \return a failure handler throwing exception in case of failure
108168
[[nodiscard]] FailureHandler<FailureHandlerPolicy::RAISE>
109169
getThrowingFailureHandler() noexcept;
170+
110171
//! \return a failure handler aborting the execution in case of failure
111172
[[nodiscard]] FailureHandler<FailureHandlerPolicy::ABORT>
112173
getFatalFailureHandler() noexcept;
174+
113175
/*!
114176
* \brief set the current log stream.
115177
* \param[in] s: log stream
116178
* \note the user is responsible for ensuring that the given object is alive
117179
*/
118180
void setLogStream(std::ostream &) noexcept;
181+
119182
/*!
120183
* \brief set the current log stream.
121184
* \param[in] s: log stream
@@ -124,24 +187,29 @@ namespace mgis {
124187
* free function.
125188
*/
126189
void setLogStream(std::shared_ptr<std::ostream>) noexcept;
190+
127191
//! \return a pointer to a log stream. This pointer may be null.
128192
[[nodiscard]] std::shared_ptr<std::ostream> getLogStreamPointer()
129193
const noexcept;
194+
130195
//! \brief reset the default log stream
131196
void resetLogStream() noexcept;
197+
132198
/*!
133-
* \brief disable the default log stream
199+
* \brief disable the default log stream
134200
*
135201
* \note logging is disable by creating a no-op output stream
136202
*/
137203
void disableLogStream() noexcept;
204+
138205
/*!
139206
* \return the current log stream
140207
*
141208
* \note if no log stream is set, the default one is returned. See
142209
* `getDefaultLogStream` for details.
143210
*/
144211
[[nodiscard]] std::ostream &log() noexcept;
212+
145213
/*!
146214
* \brief display the given arguments in the log stream if the current
147215
* verbosity level (as returned by the `getVerbosityLevel` method) is
@@ -156,6 +224,7 @@ namespace mgis {
156224
*/
157225
template <typename... Args>
158226
std::ostream &log(const VerbosityLevel, Args &&...) noexcept;
227+
159228
/*!
160229
* \brief a simple wrapper around the `log` method to print a warning
161230
*
@@ -164,6 +233,7 @@ namespace mgis {
164233
*/
165234
template <typename... Args>
166235
void warning(Args &&...) noexcept;
236+
167237
/*!
168238
* \brief a simple wrapper around the `log` method which sets the minimun
169239
* verbosity level to `verboseDebug`
@@ -175,26 +245,44 @@ namespace mgis {
175245
*/
176246
template <typename... Args>
177247
void debug(Args &&...) noexcept;
248+
178249
//! \brief destructor
179250
~Context() noexcept override;
180251

181252
private:
182253
//! \brief printing the error message on the log stream and abort the
183254
//! execution
184255
[[noreturn]] void abort();
256+
185257
//! \brief current log stream
186258
std::variant<std::monostate, std::ostream *, std::shared_ptr<std::ostream>>
187259
log_stream;
260+
188261
/*!
189262
* \brief local level of verbosity, initialize by the
190263
* global option returned by the `getVerbosityLevel`
191264
* function
192265
*/
193266
VerbosityLevel verbosity;
267+
268+
//! \brief boolean stating whether profiling is enabled
269+
bool profiling_enabled = false;
270+
271+
//! \brief root node of the profiling tree containing all recorded sections
272+
ProfilingData root_profiling_data;
273+
274+
/*!
275+
* \brief Keeps track of the current path in the profiling tree.
276+
*
277+
* \note This stack does not manage memory. The lifetime and memory management of
278+
* the ProfilingData nodes are strictly handled by the tree structure itself.
279+
*/
280+
std::vector<ProfilingData*> profiling_stack;
281+
194282
}; // end of class Context
195283

196284
} // end of namespace mgis
197285

198286
#include "MGIS/Context.ixx"
199287

200-
#endif /* LIB_MGIS_CONTEXT_HXX */
288+
#endif /* LIB_MGIS_CONTEXT_HXX */

include/MGIS/Profiling.hxx

Lines changed: 47 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,47 @@
1+
#ifndef LIB_MGIS_PROFILING_HXX
2+
#define LIB_MGIS_PROFILING_HXX 1
3+
4+
#include <chrono>
5+
#include <string>
6+
#include "MGIS/Config.hxx"
7+
8+
#define MGIS_CONCAT(a, b) MGIS_CONCAT_INNER(a, b)
9+
#define MGIS_CONCAT_INNER(a, b) a##b
10+
#define MGIS_VARNAME() MGIS_CONCAT(mgis_timer_, __COUNTER__)
11+
12+
#define CatchTimeSection(CTX, NAME) \
13+
mgis::ProfilingSection MGIS_VARNAME()(CTX, NAME, (CTX).isProfilingEnabled())
14+
#define CatchLocalTimeSection(CTX, NAME, IS_ENABLED) \
15+
mgis::ProfilingSection MGIS_VARNAME()(CTX, NAME, IS_ENABLED)
16+
17+
namespace mgis {
18+
19+
class Context;
20+
21+
class MGIS_EXPORT ProfilingSection {
22+
public:
23+
//! \brief Standard constructor (active or inactive depending on the 'enabled' flag)
24+
ProfilingSection(Context& ctx,
25+
std::string,
26+
bool) noexcept;
27+
28+
//! \brief Default constructor (fallback, always inactive)
29+
ProfilingSection() noexcept : ctx_ptr(nullptr), active(false) {}
30+
31+
~ProfilingSection() noexcept;
32+
33+
ProfilingSection(const ProfilingSection&) = delete;
34+
ProfilingSection& operator=(const ProfilingSection&) = delete;
35+
36+
ProfilingSection(ProfilingSection&&) = delete;
37+
ProfilingSection& operator=(ProfilingSection&&) = delete;
38+
39+
private:
40+
Context* ctx_ptr;
41+
bool active;
42+
std::chrono::high_resolution_clock::time_point start;
43+
};
44+
45+
} // end of namespace mgis
46+
47+
#endif

0 commit comments

Comments
 (0)