Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
112 changes: 112 additions & 0 deletions docs/web/profiling.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,112 @@
---
title: Profiling system in `MGIS`
author: Julien Rigal, Thomas Helfer
date: 2026
lang: en-EN
numbersections: true
documentclass: article
from: markdown+tex_math_single_backslash
geometry:
- margin=2cm
papersize: a4
link-citations: true
colorlinks: true
figPrefixTemplate: "$$i$$"
tabPrefixTemplate: "$$i$$"
secPrefixTemplate: "$$i$$"
eqnPrefixTemplate: "($$i$$)"
bibliography: bibliography.bib
---

This section describes the profiling system introduced in `MGIS`, which is meant to:

1. provide a hierarchical and precise measurement of execution times across the library.
2. ensure minimal to zero overhead when disabled, preserving the high-performance computing requirements of the code.

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.

# The `ProfilingData` structure

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:

- `name`: A `std::string` representing the name of the profiled section.
- `time_in_seconds`: A `double` accumulating the total time spent in this section.
- `calls`: An `unsigned int` counting the number of times this section was executed.
- `children`: A `std::vector` of `std::shared_ptr<ProfilingData>`, representing the nested profiled sections called within the current one.

# Managing the Profiling State

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:

- `enableProfiling(bool)`: Turns the global profiling on or off for the given context.
- `isProfilingEnabled()`: Returns a boolean indicating the current state of the profiler.
- `getProfilingResultTree()`: Retrieves the root node of the profiling tree (`ProfilingData`) containing all the collected metrics.

# Instrumenting the code

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.

To ensure high readability and ease of use, this mechanism is wrapped in macros.

## The `CatchTimeSection` macro

The `CatchTimeSection` macro is the standard way to profile a block of code. It takes two arguments:
1. The `Context` object.
2. A string literal representing the name of the section.

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.

## The `CatchLocalTimeSection` macro

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:

~~~~{.cxx}
// The third argument 'true' forces the profiling of this specific scope
CatchLocalTimeSection(ctx, "ForcedSection", true);
~~~~

# Aggregation and Loops

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.

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`.

# Example of usage

The following code illustrates how to instrument a function and how the tree hierarchy and loop aggregation behave:

~~~~{.cxx}
void performComputation(mgis::Context& ctx)
{
ctx.enableProfiling(true);

// Start a root section
{
CatchTimeSection(ctx, "IntegrationStep");

// Nested section
{
CatchTimeSection(ctx, "Initialization");
// ... initialization code ...
}

// Loop with a nested section
for (int i = 0; i < 1000; ++i) {
CatchTimeSection(ctx, "NewtonRaphsonIteration");
// ... solver code ...
}
}

// Retrieve and analyze the results
const auto& root = ctx.getProfilingResultTree();
// 'root' contains 1 child: "IntegrationStep"
// "IntegrationStep" contains 2 children: "Initialization" and "NewtonRaphsonIteration"
// "NewtonRaphsonIteration" will show: calls = 1000
}
~~~~

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.

> **Note**
>
> Exhaustive examples and unit tests of the profiling system, including edge cases, can be found in the `tests/ProfilingTest.cxx` file.
2 changes: 2 additions & 0 deletions include/CMakeLists.txt
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,8 @@ mgis_header(MGIS Contract.hxx)
mgis_header(MGIS Contract.ixx)
mgis_header(MGIS Context.hxx)
mgis_header(MGIS Context.ixx)
mgis_header(MGIS ProfilingData.hxx)
mgis_header(MGIS Profiling.hxx)
mgis_header(MGIS ErrorBacktrace.hxx)
mgis_header(MGIS InvalidResult.hxx)
mgis_header(MGIS InvalidResult.ixx)
Expand Down
94 changes: 91 additions & 3 deletions include/MGIS/Context.hxx
Original file line number Diff line number Diff line change
Expand Up @@ -10,11 +10,14 @@
#include <memory>
#include <variant>
#include <ostream>
#include <vector>
#include "MGIS/Config.hxx"
#include "MGIS/Raise.hxx"
#include "MGIS/LogStream.hxx"
#include "MGIS/VerbosityLevel.hxx"
#include "MGIS/ErrorBacktrace.hxx"
#include "MGIS/ProfilingData.hxx"
#include "MGIS/Profiling.hxx"

namespace mgis {

Expand All @@ -29,7 +32,7 @@ namespace mgis {

/*!
* \brief a class used to pass an execution context to most methods of
* `MGIS` and gather information (error, logs).
* `MGIS` and gather information (error, logs, profiling).
*
* The default logging stream is the one returned by the
* `mgis::getDefaultLogStream` free function.
Expand Down Expand Up @@ -71,13 +74,15 @@ namespace mgis {
//! \brief reference to the context that created the failure handler
Context &ctx;
};

/*!
* \brief default constructor
*
* The verbositiy level is initialized by calling the
* `getDefaultVerbosityLevel` function.
*/
Context() noexcept;

/*!
* \brief constructor for an initializer
* \param[in] i: initializer
Expand All @@ -90,11 +95,65 @@ namespace mgis {
Context &operator=(const Context &) = delete;
//! \return the verbosity level
[[nodiscard]] const VerbosityLevel &getVerbosityLevel() const noexcept;

/*!
* \brief change the level of verbosity
* \param[in] l: the new verbose level
*/
void setVerbosityLevel(const VerbosityLevel) noexcept;

/*!
* \brief enable or disable profiling
* \param[in] b: a boolean value stating whether profiling shall be enabled
*
* \note when profiling is disabled, profiling sections introduce
* almost no overhead.
*/
void enableProfiling(const bool) noexcept;

/*!
* \return true if profiling is enabled, false otherwise
*/
[[nodiscard]] bool isProfilingEnabled() const noexcept;

/*!
* \brief start a new profiling section
* \param[in] name: name of the profiling section
* \param[in] enabled: boolean stating whether this profiling section
* shall effectively collect timing information
*
* \return a profiling section object
*
* \note the returned object relies on RAII semantics:
* timing starts during construction and stops during destruction.
*/
[[nodiscard]] ProfilingSection startNewProfiling(
std::string,
bool) noexcept;

/*!
* \brief push a new profiling node into the current execution stack
* \param[in] name: name of the profiling section
*
* \note this method is meant to be called internally by the
* `Profiling` class during its construction.
*/
void pushProfilingNode(std::string) noexcept;

/*!
* \brief pop the current profiling node from the execution stack and accumulate time
* \param[in] dt: execution time of the section in seconds
*
* \note this method is meant to be called internally by the
* `Profiling` class during its destruction.
*/
void popProfilingNode(double) noexcept;

/*!
* \return the root node of the profiling results tree gathered during execution
*/
[[nodiscard]] const ProfilingData& getProfilingResultTree() const noexcept;

/*!
* \return a failure handler
* \tparam policy: policy used to treat a failure
Expand All @@ -104,18 +163,22 @@ namespace mgis {
[[nodiscard]] FailureHandler<policy> getFailureHandler() {
return FailureHandler<policy>{*this};
}

//! \return a failure handler throwing exception in case of failure
[[nodiscard]] FailureHandler<FailureHandlerPolicy::RAISE>
getThrowingFailureHandler() noexcept;

//! \return a failure handler aborting the execution in case of failure
[[nodiscard]] FailureHandler<FailureHandlerPolicy::ABORT>
getFatalFailureHandler() noexcept;

/*!
* \brief set the current log stream.
* \param[in] s: log stream
* \note the user is responsible for ensuring that the given object is alive
*/
void setLogStream(std::ostream &) noexcept;

/*!
* \brief set the current log stream.
* \param[in] s: log stream
Expand All @@ -124,24 +187,29 @@ namespace mgis {
* free function.
*/
void setLogStream(std::shared_ptr<std::ostream>) noexcept;

//! \return a pointer to a log stream. This pointer may be null.
[[nodiscard]] std::shared_ptr<std::ostream> getLogStreamPointer()
const noexcept;

//! \brief reset the default log stream
void resetLogStream() noexcept;

/*!
* \brief disable the default log stream
* \brief disable the default log stream
*
* \note logging is disable by creating a no-op output stream
*/
void disableLogStream() noexcept;

/*!
* \return the current log stream
*
* \note if no log stream is set, the default one is returned. See
* `getDefaultLogStream` for details.
*/
[[nodiscard]] std::ostream &log() noexcept;

/*!
* \brief display the given arguments in the log stream if the current
* verbosity level (as returned by the `getVerbosityLevel` method) is
Expand All @@ -156,6 +224,7 @@ namespace mgis {
*/
template <typename... Args>
std::ostream &log(const VerbosityLevel, Args &&...) noexcept;

/*!
* \brief a simple wrapper around the `log` method to print a warning
*
Expand All @@ -164,6 +233,7 @@ namespace mgis {
*/
template <typename... Args>
void warning(Args &&...) noexcept;

/*!
* \brief a simple wrapper around the `log` method which sets the minimun
* verbosity level to `verboseDebug`
Expand All @@ -175,26 +245,44 @@ namespace mgis {
*/
template <typename... Args>
void debug(Args &&...) noexcept;

//! \brief destructor
~Context() noexcept override;

private:
//! \brief printing the error message on the log stream and abort the
//! execution
[[noreturn]] void abort();

//! \brief current log stream
std::variant<std::monostate, std::ostream *, std::shared_ptr<std::ostream>>
log_stream;

/*!
* \brief local level of verbosity, initialize by the
* global option returned by the `getVerbosityLevel`
* function
*/
VerbosityLevel verbosity;

//! \brief boolean stating whether profiling is enabled
bool profiling_enabled = false;

//! \brief root node of the profiling tree containing all recorded sections
ProfilingData root_profiling_data;

/*!
* \brief Keeps track of the current path in the profiling tree.
*
* \note This stack does not manage memory. The lifetime and memory management of
* the ProfilingData nodes are strictly handled by the tree structure itself.
*/
std::vector<ProfilingData*> profiling_stack;

}; // end of class Context

} // end of namespace mgis

#include "MGIS/Context.ixx"

#endif /* LIB_MGIS_CONTEXT_HXX */
#endif /* LIB_MGIS_CONTEXT_HXX */
47 changes: 47 additions & 0 deletions include/MGIS/Profiling.hxx
Original file line number Diff line number Diff line change
@@ -0,0 +1,47 @@
#ifndef LIB_MGIS_PROFILING_HXX
#define LIB_MGIS_PROFILING_HXX 1

#include <chrono>
#include <string>
#include "MGIS/Config.hxx"

#define MGIS_CONCAT(a, b) MGIS_CONCAT_INNER(a, b)
#define MGIS_CONCAT_INNER(a, b) a##b
#define MGIS_VARNAME() MGIS_CONCAT(mgis_timer_, __COUNTER__)

#define CatchTimeSection(CTX, NAME) \
mgis::ProfilingSection MGIS_VARNAME()(CTX, NAME, (CTX).isProfilingEnabled())
#define CatchLocalTimeSection(CTX, NAME, IS_ENABLED) \
mgis::ProfilingSection MGIS_VARNAME()(CTX, NAME, IS_ENABLED)

namespace mgis {

class Context;

class MGIS_EXPORT ProfilingSection {
public:
//! \brief Standard constructor (active or inactive depending on the 'enabled' flag)
ProfilingSection(Context& ctx,
std::string,
bool) noexcept;

//! \brief Default constructor (fallback, always inactive)
ProfilingSection() noexcept : ctx_ptr(nullptr), active(false) {}

~ProfilingSection() noexcept;

ProfilingSection(const ProfilingSection&) = delete;
ProfilingSection& operator=(const ProfilingSection&) = delete;

ProfilingSection(ProfilingSection&&) = delete;
ProfilingSection& operator=(ProfilingSection&&) = delete;

private:
Context* ctx_ptr;
bool active;
std::chrono::high_resolution_clock::time_point start;
};

} // end of namespace mgis

#endif
Loading
Loading