Commit 52739195 authored by Pádraig Ó Conbhuí's avatar Pádraig Ó Conbhuí
Browse files

Add initial working version

parent b2f4f08c
build/
make.sh
cmake_minimum_required(VERSION 3.13)
project(
perforate
VERSION 0.0.1
DESCRIPTION "Fast C++ tracing / timing"
LANGUAGES CXX
)
add_library(perforate INTERFACE)
target_include_directories(perforate INTERFACE src)
target_compile_features(perforate INTERFACE cxx_std_14)
add_library(perforate::perforate ALIAS perforate)
option(PERFORATE_ENABLE_TESTING "Enable testing for Perforate" ON)
if(PERFORATE_ENABLE_TESTING)
enable_testing()
add_subdirectory(tests)
add_executable(perforate.test src/perforate/scoped_trace.test.cpp)
target_link_libraries(
perforate.test
PRIVATE
perforate::perforate
perforate::catch2_runner
)
target_include_directories(perforate.test PRIVATE src)
add_test(
NAME perforate.test
COMMAND perforate.test
)
# Setup benchmarks
add_custom_target(bench)
add_executable(
perforate.bench EXCLUDE_FROM_ALL
src/perforate/scoped_trace.bench.cpp
)
target_link_libraries(
perforate.bench
PRIVATE
perforate::perforate
perforate::catch2_runner
)
add_dependencies(bench perforate.bench)
add_custom_command(
TARGET bench
POST_BUILD
COMMAND perforate.bench
)
endif()
#define CATCH_CONFIG_ENABLE_BENCHMARKING
#include "perforate/scoped_trace.hpp"
#include <catch2/catch.hpp>
#include <chrono>
#include <vector>
TEST_CASE("perforate::scoped_trace", "[scoped_trace][benchmark]")
{
BENCHMARK("std::chrono::high_resolution_clock::now()")
{
return std::chrono::high_resolution_clock::now();
};
BENCHMARK("scoped_trace overhead")
{
PERFORATE_SCOPED_TRACE(nullptr);
};
}
#ifndef PERFORATE_TRACE_HPP
#define PERFORATE_TRACE_HPP
#include <algorithm>
#include <cassert>
#include <chrono>
#include <cinttypes>
#include <cstddef>
#include <iostream>
#include <iterator>
#include <memory>
#include <utility>
#include <vector>
namespace perforate {
namespace detail {
// A class containing a static instance of the type constructed by
// `type_policy::make()`, unique for each Tag.
// Contains accessors suitable for pre-main avoiding the
// "Static Initialization Order Fiasco" (SIOF)
template<typename type_policy>
class per_tag {
public:
using policy_type = typename type_policy::type;
private:
// A SIOF-safe holder for a static instance of type_policy.
static type_policy& policy_singleton()
{
static type_policy m_policy{};
return m_policy;
}
template<typename Tag>
class per_tag_singleton {
public:
// SIOF-safe
static policy_type& safe_value()
{
static policy_type m_safe_value =
policy_singleton().template make<Tag>();
return m_safe_value;
}
// SIOF-unsafe, but without extra checking
static policy_type& value;
};
public:
// Get an instance of the underlying policy
static const type_policy& policy() { return policy_singleton(); }
//
// Accessors suitable for post-main access, not safe for SIOF situations
//
template<typename Tag>
static policy_type& value()
{
return per_tag_singleton<Tag>::value;
}
template<typename Tag>
static policy_type& value(Tag&&)
{
return value<Tag>();
}
//
// Accessors suitable for pre-main access, safe for SIOF situations
//
template<typename Tag>
static policy_type& safe_value()
{
return per_tag_singleton<Tag>::safe_value();
}
template<typename Tag>
static policy_type& safe_value(Tag&&)
{
return safe_value<Tag>();
}
};
template<typename type_policy>
template<typename Tag>
typename per_tag<type_policy>::policy_type&
per_tag<type_policy>::per_tag_singleton<Tag>::value =
per_tag<type_policy>::per_tag_singleton<Tag>::safe_value();
// A class containing the range name, accumulated time and call count.
// This is used to track the total time spent in a scope, and the number of
// times the scope has been entered. This can be used to calculate the
// average duration of the scope.
//
// The class is thread safe, with accumulated times and call counts eventually
// consistent, by the time all scopes in all threads are closed.
//
class range_stats {
const char* m_range_name {nullptr};
std::atomic<int64_t> m_accumulated_ns {0};
std::atomic<int64_t> m_call_count {0};
public:
void set_range_name(const char* range_name) { m_range_name = range_name; }
const char* range_name() const { return m_range_name; }
std::chrono::nanoseconds accumulated_time() const
{
return std::chrono::nanoseconds{m_accumulated_ns.load()};
}
int64_t call_count() const { return m_call_count.load(); }
void add_range(std::chrono::nanoseconds time, size_t calls)
{
m_accumulated_ns += time.count();
m_call_count += calls;
}
// Default constructible, not movable or copyable.
range_stats() = default;
~range_stats() = default;
range_stats(const range_stats&) = delete;
range_stats& operator=(const range_stats&) = delete;
range_stats(range_stats&&) = delete;
range_stats& operator=(range_stats&&) = delete;
};
template<typename Stream, typename Stats>
void print_range_stats(Stream& stream, const Stats& stats)
{
const std::chrono::nanoseconds accumulated_ns = stats.accumulated_time();
const double accumulated_seconds = accumulated_ns.count() * 1e-9;
stream << stats.range_name() << ": " << accumulated_seconds << " s, "
<< (accumulated_seconds / stats.call_count()) << " s/call, "
<< stats.call_count() << " call(s)\n";
}
template<typename Stream, typename StatsPtrList>
void print_range_stats_list(Stream& stream, const StatsPtrList& stats_ptr_list)
{
const auto empty = [](const auto& stats) {
return stats->range_name() == nullptr;
};
const auto registry_empty = std::all_of(
std::cbegin(stats_ptr_list), std::cend(stats_ptr_list), empty);
if (!registry_empty) {
stream << "\n------------"
<< "\nRange Stats:"
<< "\n------------\n";
for (const auto& s : stats_ptr_list) {
if (s->range_name() == nullptr) continue;
print_range_stats(stream, *s);
}
stream << "\n------------\n";
}
}
class range_stats_print_on_exit_policy {
std::vector<range_stats*> m_range_stats_list{};
public:
using type = range_stats&;
const std::vector<range_stats*>& range_stats_list() const
{
return m_range_stats_list;
}
template<typename Tag>
range_stats& make()
{
static range_stats m_tag_range_stats{};
m_range_stats_list.emplace_back(&m_tag_range_stats);
return m_tag_range_stats;
}
~range_stats_print_on_exit_policy()
{
print_range_stats_list(std::cout, m_range_stats_list);
}
};
class per_tag_range_stats : public per_tag<range_stats_print_on_exit_policy> {
};
} // namespace detail
template<
typename Tag,
size_t AggregateCount = 1,
typename Clock = std::chrono::high_resolution_clock>
class scoped_trace {
static_assert(
(AggregateCount & (AggregateCount - 1)) == 0,
"AggregateCount must be a power of 2");
using time_point = typename Clock::time_point;
time_point m_t0 = Clock::now();
bool m_active = true;
static detail::range_stats& stats()
{
return detail::per_tag_range_stats::value<Tag>();
}
public:
scoped_trace(const char* range_name)
{
assert(
stats().range_name() == nullptr
|| stats().range_name() == range_name);
stats().set_range_name(range_name);
}
scoped_trace(const scoped_trace&) = delete;
scoped_trace& operator=(const scoped_trace&) = delete;
// Move constructor marks other as inactive
scoped_trace(scoped_trace&& other) :
m_t0{std::move(other.m_t0)},
m_active{std::exchange(other.m_active, false)}
{
}
scoped_trace& operator=(scoped_trace&& other)
{
if (this != &other) {
m_t0 = std::move(other.m_t0);
m_active = std::exchange(other.m_active, false);
}
return *this;
}
~scoped_trace()
{
if (m_active) {
const auto now = Clock::now();
const auto delta = now - m_t0;
auto& s = stats();
s.add_range(delta, 1);
if (AggregateCount != 0 && s.call_count() % AggregateCount == 0) {
detail::print_range_stats(std::cout, s);
}
}
}
};
template<typename Tag, size_t AggregateCount = 0>
[[nodiscard]] auto make_scoped_trace(const char* range_name)
{
return scoped_trace<Tag, AggregateCount>(range_name);
}
template<size_t AggregateCount = 0, typename Tag = void>
[[nodiscard]] auto make_scoped_trace(const char* range_name, Tag&&)
{
return make_scoped_trace<Tag, AggregateCount>(range_name);
}
// Some machinery to make token concatenation work in macros
#define PERFORATE_DETAIL_COMBINE_1(X, Y) X##Y
#define PERFORATE_DETAIL_COMBINE(X, Y) PERFORATE_DETAIL_COMBINE_1(X, Y)
// Create a scopes trace with a unique tag
#define PERFORATE_SCOPED_TRACE_V(RANGE_NAME) \
::perforate::make_scoped_trace(RANGE_NAME, [] {})
// Create a scoped trace with an "anonymous" variable name
// Note: this not be called outside a function scope!
#define PERFORATE_SCOPED_TRACE(RANGE_NAME) \
auto PERFORATE_DETAIL_COMBINE(_perforate_scoped_trace_v_, __LINE__) = \
PERFORATE_SCOPED_TRACE_V(RANGE_NAME)
// End a scoped_trace early by "std::move"ing into this sink function
template<typename Tag, size_t AggregateCount>
void end_scoped_trace(scoped_trace<Tag, AggregateCount>)
{
}
} // namespace perforate
#endif // PERFORATE_TRACE_HPP
#include "perforate/scoped_trace.hpp"
#include <catch2/catch.hpp>
#include <algorithm>
#include <chrono>
#include <iterator>
#include <ratio>
#include <set>
#include <string>
#include <utility>
// Test detail::per_tag
class per_tag_test_helper {
public:
// Make a unique index per type
class index_policy {
public:
using type = int64_t;
type index;
template<typename Tag>
type make()
{
return ++index;
}
};
class type_index : public perforate::detail::per_tag<index_policy> {
};
};
using per_tag_index = per_tag_test_helper::type_index;
// Generate some pre-main indices
auto index_1 = per_tag_index::safe_value<class index_1_tag>();
auto index_2 = per_tag_index::safe_value<class index_2_tag>();
// Generate indices using lambdas as unique types
auto index_3 = per_tag_index::safe_value([] {});
auto index_4 = per_tag_index::safe_value([] {});
// Generate indices inside a templated context
template<typename Tag>
struct templated_per_tag_index {
auto value() const
{
return per_tag_index::value([] {});
}
};
TEST_CASE(
"detail::per_tag should create unique instances for unique types",
"[per_tag]")
{
// Test an index was generated by per_tag_index::policy before calling
// this function.
const auto policy_index = per_tag_index::policy().index + 1;
const auto generated_pre_main = [policy_index](int64_t i) {
return i <= policy_index;
};
// Test an index hasn't been encountered by this function yet
std::set<int64_t> indices;
const auto index_is_unique = [&indices](int64_t i) {
const auto result = indices.insert(i);
return result.second == true;
};
{
INFO("Indices generated before main should be unique");
REQUIRE(generated_pre_main(index_1));
REQUIRE(index_is_unique(index_1));
REQUIRE(index_1 == per_tag_index::value<class index_1_tag>());
REQUIRE(generated_pre_main(index_2));
REQUIRE(index_is_unique(index_2));
REQUIRE(index_2 == per_tag_index::value<class index_2_tag>());
REQUIRE(generated_pre_main(index_3));
REQUIRE(index_is_unique(index_3));
REQUIRE(generated_pre_main(index_4));
REQUIRE(index_is_unique(index_4));
}
{
INFO("Indices generated after main should be unique");
auto index_5 = per_tag_index::value<class index_5_tag>();
REQUIRE(generated_pre_main(index_5));
REQUIRE(index_is_unique(index_5));
auto index_6 = per_tag_index::value<class index_6_tag>();
REQUIRE(generated_pre_main(index_6));
REQUIRE(index_is_unique(index_6));
auto index_7 = per_tag_index::value([] {});
REQUIRE(generated_pre_main(index_7));
REQUIRE(index_is_unique(index_7));
auto index_8 = per_tag_index::value([] {});
REQUIRE(generated_pre_main(index_8));
REQUIRE(index_is_unique(index_8));
}
{
INFO("Indices generated inside templated contexts should be unique");
auto index_9 = templated_per_tag_index<class index_9_tag>{}.value();
REQUIRE(generated_pre_main(index_9));
REQUIRE(index_is_unique(index_9));
auto index_10 = templated_per_tag_index<class index_10_tag>{}.value();
REQUIRE(generated_pre_main(index_10));
REQUIRE(index_is_unique(index_10));
}
{
INFO(
"Calling index twice for the same type should have the same index");
REQUIRE(
per_tag_index::value<class same_tag>()
== per_tag_index::value<class same_tag>());
}
}
auto& rs_1 =
perforate::detail::per_tag_range_stats::safe_value<class rs_1_tag>();
auto& rs_2 =
perforate::detail::per_tag_range_stats::safe_value<class rs_2_tag>();
TEST_CASE(
"Unique types should have unique range_stats",
"[range_stats][per_tag_range_stats][range_stats_print_on_exit_policy]")
{
SECTION ("declared range_stats should be accessible by the registry") {
const auto is_in_registry =
[](const perforate::detail::range_stats& rs) {
// Check by memory location
const auto& stats_list =
perforate::detail::per_tag_range_stats::policy()
.range_stats_list();
return std::any_of(
std::cbegin(stats_list), std::cend(stats_list),
[&](const auto* e) { return e == &rs; });
};
REQUIRE(is_in_registry(rs_1));
REQUIRE(is_in_registry(rs_2));
// Even bespokely generated range_stats should be in the registry
REQUIRE(is_in_registry(
perforate::detail::per_tag_range_stats::value([] {})));
}
}
struct test_clock {
using rep = size_t;
using period = std::ratio<1, 1>;
using duration = std::chrono::duration<rep, period>;
using time_point = std::chrono::time_point<test_clock>;
static duration elapsed_time;
static time_point now() { return time_point(elapsed_time); }
};
test_clock::duration test_clock::elapsed_time{};
TEST_CASE("test_clock sanity check", "[test_clock]")
{
SECTION ("test_clock::now() can be set from test_clock::elapsed_time") {
test_clock::elapsed_time = std::chrono::seconds(0);
const auto t0 = test_clock::now();
test_clock::elapsed_time = std::chrono::seconds(1);
const auto t1 = test_clock::now();
REQUIRE(t1 - t0 == std::chrono::seconds(1));
SECTION ("test_clock counts in seconds") {
REQUIRE((t1 - t0).count() == 1);
}
}
}
TEST_CASE("scoped_trace should trace / time a scope", "[scoped_trace]")
{
const auto& stats_list =
perforate::detail::per_tag_range_stats::policy().range_stats_list();
SECTION ("scoped_trace should create an entry in range_stats_list") {
class st_1_tag;
{
test_clock::elapsed_time = std::chrono::seconds(0);
const auto st =
perforate::scoped_trace<st_1_tag, 0, test_clock>{"test::st_1"};
test_clock::elapsed_time = std::chrono::seconds(10);
}
const auto stats_it = std::find_if(
std::cbegin(stats_list), std::cend(stats_list),
[](const auto* stats) {
if (stats->range_name() == nullptr) return false;
return std::string{stats->range_name()} == "test::st_1";
});
REQUIRE(stats_it != std::cend(stats_list));
REQUIRE(std::string{(**stats_it).range_name()} == "test::st_1");
REQUIRE((**stats_it).accumulated_time() == std::chrono::seconds(10));
REQUIRE((**stats_it).call_count() == 1);
// Expect the value found to equal the actual value
REQUIRE(
&**stats_it
== &perforate::detail::per_tag_range_stats::value<st_1_tag>());
}
SECTION ("multiple calls with scoped_trace should generate statistics") {
test_clock::elapsed_time = std::chrono::seconds(0);
const size_t num_calls = 100;
for (size_t i = 0; i < num_calls; i++) {
test_clock::elapsed_time += std::chrono::seconds(1);