Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Implement CallProfiler #258

Closed
wants to merge 3 commits into from
Closed
Show file tree
Hide file tree
Changes from 1 commit
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
1 change: 1 addition & 0 deletions cpp/modmesh/toggle/CMakeLists.txt
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ cmake_minimum_required(VERSION 3.16)
set(MODMESH_TOGGLE_HEADERS
${CMAKE_CURRENT_SOURCE_DIR}/profile.hpp
${CMAKE_CURRENT_SOURCE_DIR}/RadixTree.hpp
${CMAKE_CURRENT_SOURCE_DIR}/callprofiler.hpp
${CMAKE_CURRENT_SOURCE_DIR}/toggle.hpp
CACHE FILEPATH "" FORCE)

Expand Down
8 changes: 8 additions & 0 deletions cpp/modmesh/toggle/RadixTree.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -162,6 +162,14 @@ class RadixTree
}
}

void reset()
{
m_root = std::move(std::make_unique<RadixTreeNode<T>>());
m_current_node = m_root.get();
m_id_map.clear();
m_unique_id = 0;
}

RadixTreeNode<T> * get_current_node() const { return m_current_node; }
key_type get_unique_node() const { return m_unique_id; }

Expand Down
134 changes: 134 additions & 0 deletions cpp/modmesh/toggle/callprofiler.hpp
Original file line number Diff line number Diff line change
@@ -0,0 +1,134 @@
#pragma once
#include <chrono>
#include <ostream>
#include <stack>
#include <unordered_map>
#include "RadixTree.hpp"

namespace modmesh
{

// Define a structure for each node in the radix tree
struct CallerProfile
{
std::string functionName;
std::chrono::milliseconds totalTime;
int callCount = 0;
};

// Define a structure to represent a function call
struct CallerInfo
{
std::string callerName;
std::chrono::high_resolution_clock::time_point startTime;
};

class CallProfiler
{
public:
/// A singleton.
static CallProfiler & instance()
{
static CallProfiler instance;
return instance;
}

// Called when a function starts
void start_caller(const std::string & callerName)
{
auto startTime = std::chrono::high_resolution_clock::now();
m_callStack.push({callerName, startTime});
m_radixTree.entry(callerName);
}

// Called when a function ends
void end_caller()
{
auto endTime = std::chrono::high_resolution_clock::now();
auto elapsedTime = std::chrono::duration_cast<std::chrono::milliseconds>(endTime - m_callStack.top().startTime);

// Update the radix tree with profiling information
auto & callerName = m_callStack.top().callerName;

CallerProfile & callProfile = m_radixTree.get_current_node()->data();

// Update profiling information
callProfile.totalTime += elapsedTime;
callProfile.callCount++;
callProfile.functionName = callerName;

// Pop the function from the call stack
m_callStack.pop();
m_radixTree.move_current_to_parent();
}

/// Print the profiling information
void print_profiling_result(std::ostream & outstream) const
{
_print_profiling_result(*(m_radixTree.get_current_node()), 0, outstream);
}

void reset()
{
while (!m_callStack.empty())
{
m_callStack.pop();
}
m_radixTree.reset();
}

private:
CallProfiler() = default;

void _print_profiling_result(const RadixTreeNode<CallerProfile> & node, const int depth, std::ostream & outstream) const
{
for (int i = 0; i < depth; ++i)
{
outstream << " ";
}

auto profile = node.data();

if (depth == 0)
{
outstream << "Profiling Result" << std::endl;
}
else
{
outstream << profile.functionName << " - Total Time: " << profile.totalTime.count() << " ms, Call Count: " << profile.callCount << std::endl;
}

for (const auto & child : node.children())
{
_print_profiling_result(*child, depth + 1, outstream);
}
}

private:
std::stack<CallerInfo> m_callStack;
RadixTree<CallerProfile> m_radixTree;
};

/// Utility to time how long a scope takes
class CallProfilerProbe
{
public:
CallProfilerProbe(CallProfiler & profiler, const char * callerName)
: m_profiler(profiler)
{
m_profiler.start_caller(callerName);
}

~CallProfilerProbe()
{
m_profiler.end_caller();
}

private:
CallProfiler & m_profiler;
};

#define USE_CALLPROFILER_PROFILE_THIS_FUNCTION() CallProfilerProbe __profilerProbe##__COUNTER__(modmesh::CallProfiler::instance(), __FUNCTION__)
#define USE_CALLPROFILER_PROFILE_THIS_SCOPE(scopeName) CallProfilerProbe __profilerProbe##__COUNTER__(modmesh::CallProfiler::instance(), scopeName)

} // namespace modmesh
1 change: 1 addition & 0 deletions gtests/CMakeLists.txt
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,7 @@ add_executable(
test_nopython_modmesh.cpp
test_nopython_inout.cpp
test_nopython_radixtree.cpp
test_nopython_callprofiler.cpp
)
target_link_libraries(
test_nopython
Expand Down
85 changes: 85 additions & 0 deletions gtests/test_nopython_callprofiler.cpp
Original file line number Diff line number Diff line change
@@ -0,0 +1,85 @@
#include <modmesh/toggle/callprofiler.hpp>
#include <gtest/gtest.h>
#include <thread>

#ifdef Py_PYTHON_H
#error "Python.h should not be included."
#endif

TEST(CallProfiler, construction)
{
namespace mm = modmesh;
mm::CallProfiler::instance();
}

constexpr int uniqueTime1 = 19;
constexpr int uniqueTime2 = 35;
constexpr int uniqueTime3 = 7;

void foo3()
{
modmesh::USE_CALLPROFILER_PROFILE_THIS_FUNCTION();
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we use the macro here to insert the profiler.

std::this_thread::sleep_for(std::chrono::milliseconds(uniqueTime1));
}

void foo2()
{
modmesh::USE_CALLPROFILER_PROFILE_THIS_FUNCTION();
std::this_thread::sleep_for(std::chrono::milliseconds(uniqueTime2));
foo3();
}

void foo1()
{
modmesh::USE_CALLPROFILER_PROFILE_THIS_FUNCTION();
foo2();
std::this_thread::sleep_for(std::chrono::milliseconds(uniqueTime3));
}

TEST(CallProfilerCase1, construction)
{
namespace mm = modmesh;

mm::CallProfiler& profiler = mm::CallProfiler::instance();
profiler.reset();

foo1();

std::stringstream ss;
profiler.print_profiling_result(ss);

const char * answer = R"(Profiling Result
foo1 - Total Time: 61 ms, Call Count: 1
foo2 - Total Time: 54 ms, Call Count: 1
foo3 - Total Time: 19 ms, Call Count: 1
)";

EXPECT_EQ(ss.str(), answer);
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

just for demonstration here, I think it's better to compare each node one by one.

}

TEST(CallProfilerCase2, construction)
{
namespace mm = modmesh;

mm::CallProfiler& profiler = mm::CallProfiler::instance();
profiler.reset();

foo1();
foo2();
foo3();
foo3();

std::stringstream ss;
profiler.print_profiling_result(ss);

const char * answer = R"(Profiling Result
foo1 - Total Time: 61 ms, Call Count: 1
foo2 - Total Time: 115 ms, Call Count: 1
foo3 - Total Time: 73 ms, Call Count: 1
foo2 - Total Time: 73 ms, Call Count: 1
foo3 - Total Time: 19 ms, Call Count: 1
foo3 - Total Time: 38 ms, Call Count: 2
)";

EXPECT_EQ(ss.str(), answer);
}