diff --git a/include/hibf/build/build_data.hpp b/include/hibf/build/build_data.hpp index 0331516e..1fe577f3 100644 --- a/include/hibf/build/build_data.hpp +++ b/include/hibf/build/build_data.hpp @@ -29,10 +29,10 @@ struct build_data std::vector fpr_correction{}; // Timers do not copy the stored duration upon copy construction/assignment - mutable timer index_allocation_timer{}; - mutable timer user_bin_io_timer{}; - mutable timer merge_kmers_timer{}; - mutable timer fill_ibf_timer{}; + mutable concurrent_timer index_allocation_timer{}; + mutable concurrent_timer user_bin_io_timer{}; + mutable concurrent_timer merge_kmers_timer{}; + mutable concurrent_timer fill_ibf_timer{}; size_t request_ibf_idx() { diff --git a/include/hibf/build/insert_into_ibf.hpp b/include/hibf/build/insert_into_ibf.hpp index 09d95bc8..1995fff7 100644 --- a/include/hibf/build/insert_into_ibf.hpp +++ b/include/hibf/build/insert_into_ibf.hpp @@ -25,7 +25,7 @@ void insert_into_ibf(robin_hood::unordered_flat_set const & kmers, size_t const number_of_bins, size_t const bin_index, seqan::hibf::interleaved_bloom_filter & ibf, - timer & fill_ibf_timer); + concurrent_timer & fill_ibf_timer); //!\overload void insert_into_ibf(build_data const & data, diff --git a/include/hibf/build/update_parent_kmers.hpp b/include/hibf/build/update_parent_kmers.hpp index cb5c4f68..cf5010b0 100644 --- a/include/hibf/build/update_parent_kmers.hpp +++ b/include/hibf/build/update_parent_kmers.hpp @@ -23,9 +23,9 @@ namespace seqan::hibf::build */ inline void update_parent_kmers(robin_hood::unordered_flat_set & parent_kmers, robin_hood::unordered_flat_set const & kmers, - timer & merge_kmers_timer) + concurrent_timer & merge_kmers_timer) { - timer local_merge_kmers_timer{}; + serial_timer local_merge_kmers_timer{}; local_merge_kmers_timer.start(); parent_kmers.insert(kmers.begin(), kmers.end()); local_merge_kmers_timer.stop(); diff --git a/include/hibf/hierarchical_interleaved_bloom_filter.hpp b/include/hibf/hierarchical_interleaved_bloom_filter.hpp index f19d434c..12b9bc47 100644 --- a/include/hibf/hierarchical_interleaved_bloom_filter.hpp +++ b/include/hibf/hierarchical_interleaved_bloom_filter.hpp @@ -249,10 +249,10 @@ class hierarchical_interleaved_bloom_filter * \brief Only contains values after the HIBF has been constructed. * \{ */ - timer index_allocation_timer{}; - timer user_bin_io_timer{}; - timer merge_kmers_timer{}; - timer fill_ibf_timer{}; + concurrent_timer index_allocation_timer{}; + concurrent_timer user_bin_io_timer{}; + concurrent_timer merge_kmers_timer{}; + concurrent_timer fill_ibf_timer{}; //!\} //!\endcond }; diff --git a/include/hibf/misc/timer.hpp b/include/hibf/misc/timer.hpp index 96547608..ea049a04 100644 --- a/include/hibf/misc/timer.hpp +++ b/include/hibf/misc/timer.hpp @@ -21,168 +21,275 @@ namespace seqan::hibf { -/*!\brief Whether the timer is concurrent. - * \ingroup hibf_build +class concurrent_timer; + +/*!\brief A timer. + * \ingroup hibf */ -enum class concurrent +class serial_timer { - no, //!< Not concurrent. - yes //!< Concurrent. +private: + using steady_clock_t = std::chrono::steady_clock; + + steady_clock_t::time_point start_point{std::chrono::time_point::max()}; + steady_clock_t::time_point stop_point{}; + + steady_clock_t::rep ticks{}; + steady_clock_t::rep max{}; + uint64_t count{}; + + friend class concurrent_timer; + +public: + /*!\name Constructors, destructor and assignment + * \{ + */ + serial_timer() = default; //!< Defaulted. + serial_timer(serial_timer const &) = default; //!< Defaulted. + serial_timer & operator=(serial_timer const &) = default; //!< Defaulted. + serial_timer(serial_timer &&) = default; //!< Defaulted. + serial_timer & operator=(serial_timer &&) = default; //!< Defaulted. + ~serial_timer() = default; //!< Defaulted. + + //!\} + + /*!\name Modification + * \{ + */ + //!\brief Starts the timer. + void start() + { + start_point = steady_clock_t::now(); + } + + /*!\brief Stops the timer. + * \details + * In Debug mode, an assertion checks that `start()` has been called before. + */ + void stop() + { + stop_point = steady_clock_t::now(); + assert(stop_point >= start_point); + steady_clock_t::rep duration = (stop_point - start_point).count(); + + ticks += duration; + max = std::max(max, duration); + ++count; + } + + //!\brief Adds another timer. + template + requires (std::same_as || std::same_as) + void operator+=(timer_t const & other) + { + steady_clock_t::rep ticks_to_add{}; + if constexpr (std::same_as) + ticks_to_add = other.ticks.load(); + else + ticks_to_add = other.ticks; + + ticks += ticks_to_add; + max = std::max(max, ticks_to_add); + ++count; + } + //!\} + + /*!\name Access + * \{ + */ + //!\brief Returns the measured time in seconds. + double in_seconds() const + { + return std::chrono::duration(steady_clock_t::duration{ticks}).count(); + } + + /*!\brief Returns the maximum measured time interval in seconds. + * \details + * A time interval may be: + * * The elpased time between `start()` and `stop()`. + * * The elapsed time added via `operator+=()`. + */ + double max_in_seconds() const + { + return std::chrono::duration(steady_clock_t::duration{max}).count(); + } + + /*!\brief Returns the average measured time interval in seconds. + * \details + * A time interval may be: + * * The elpased time between `start()` and `stop()`. + * * The elapsed time added via `operator+=()`. + * + * The count used for averaging is the number of calls to `stop()` and `operator+=()`. + * \warning Calling this function when neither `stop()` or `operator+=()` have been used is undefined behaviour. + */ + double avg_in_seconds() const + { + assert(count > 0u); + return in_seconds() / count; + } + //!\} + + /*!\name Comparison + * \{ + */ + //!\brief Two timer are always equal. + constexpr bool operator==(serial_timer const &) const + { + return true; + } + + //!\brief Two timer are always equal. + constexpr bool operator==(concurrent_timer const &) const + { + return true; + } + //!\} }; -/*!\brief Timer. - * \ingroup hibf_build +/*!\brief A timer with a thread-safe `operator+=()`. + * \ingroup hibf */ -template -class timer +class concurrent_timer { private: - static constexpr bool is_concurrent{concurrency == concurrent::yes}; + using steady_clock_t = std::chrono::steady_clock; - using rep_t = - std::conditional_t, std::chrono::steady_clock::rep>; + steady_clock_t::time_point start_point{std::chrono::time_point::max()}; + steady_clock_t::time_point stop_point{}; - using count_t = std::conditional_t, uint64_t>; + alignas(64) std::atomic ticks{}; + alignas(64) std::atomic max{}; + alignas(64) std::atomic count{}; - static constexpr int alignment = is_concurrent ? 64 : 8; + friend class serial_timer; - template - friend class timer; + void update_max(steady_clock_t::rep const value) + { + for (steady_clock_t::rep previous_value = max; + previous_value < value && !max.compare_exchange_weak(previous_value, value, std::memory_order_relaxed);) + ; + } public: - timer() = default; - timer(timer &&) = default; - timer & operator=(timer &&) = default; - ~timer() = default; - - timer(timer const & other) - requires (!is_concurrent) - = default; - timer & operator=(timer const & other) - requires (!is_concurrent) - = default; - - timer(timer const & other) - requires is_concurrent - : - start_{other.start_}, - stop_{other.stop_}, + /*!\name Constructors, destructor and assignment + * \{ + */ + //!\brief Defaulted. + concurrent_timer() = default; + //!\brief Defaulted. + concurrent_timer(concurrent_timer const & other) : + start_point{other.start_point}, + stop_point{other.stop_point}, ticks{other.ticks.load()}, max{other.max.load()}, count{other.count.load()} {} - timer & operator=(timer const & other) - requires is_concurrent + //!\brief Defaulted. + concurrent_timer & operator=(concurrent_timer const & other) { - start_ = other.start_; - stop_ = other.stop_; + start_point = other.start_point; + stop_point = other.stop_point; ticks = other.ticks.load(); max = other.max.load(); count = other.count.load(); return *this; } + //!\brief Defaulted. + concurrent_timer(concurrent_timer && other) : + start_point{std::move(other.start_point)}, + stop_point{std::move(other.stop_point)}, + ticks{std::move(other.ticks.load())}, + max{std::move(other.max.load())}, + count{std::move(other.count.load())} + {} + //!\brief Defaulted. + concurrent_timer & operator=(concurrent_timer && other) + { + start_point = std::move(other.start_point); + stop_point = std::move(other.stop_point); + ticks = std::move(other.ticks.load()); + max = std::move(other.max.load()); + count = std::move(other.count.load()); + return *this; + } + //!\brief Defaulted. + ~concurrent_timer() = default; + //!\} + /*!\name Modification + * \{ + */ + //!\copydoc seqan::hibf::serial_timer::start void start() { - start_ = std::chrono::steady_clock::now(); + start_point = steady_clock_t::now(); } + /*!\copydoc seqan::hibf::serial_timer::stop + * \attention This function is **not** thread-safe. + */ void stop() { - stop_ = std::chrono::steady_clock::now(); - assert(stop_ >= start_); - std::chrono::steady_clock::rep duration = (stop_ - start_).count(); + stop_point = steady_clock_t::now(); + assert(stop_point >= start_point); + steady_clock_t::rep duration = (stop_point - start_point).count(); + ticks += duration; update_max(duration); ++count; } - template - void operator+=(timer const & other) + /*!\copydoc seqan::hibf::serial_timer::operator+= + * This function is thread-safe. + */ + template + requires (std::same_as || std::same_as) + void operator+=(timer_t const & other) { ticks += other.ticks; update_max(other.ticks); ++count; } + //!\} + /*!\name Access + * \{ + */ + //!\copydoc seqan::hibf::serial_timer::in_seconds double in_seconds() const - requires is_concurrent { - return std::chrono::duration(std::chrono::steady_clock::duration{ticks.load()}).count(); + return std::chrono::duration(steady_clock_t::duration{ticks.load()}).count(); } + //!\copydoc seqan::hibf::serial_timer::max_in_seconds double max_in_seconds() const - requires is_concurrent { - return std::chrono::duration(std::chrono::steady_clock::duration{max.load()}).count(); + return std::chrono::duration(steady_clock_t::duration{max.load()}).count(); } + //!\copydoc seqan::hibf::serial_timer::avg_in_seconds double avg_in_seconds() const - requires is_concurrent { assert(count.load() > 0u); return in_seconds() / count.load(); } - // GCOVR_EXCL_START - double in_seconds() const - requires (!is_concurrent) - { - return std::chrono::duration(std::chrono::steady_clock::duration{ticks}).count(); - } - - double max_in_seconds() const - requires (!is_concurrent) - { - return std::chrono::duration(std::chrono::steady_clock::duration{max}).count(); - } - - double avg_in_seconds() const - requires (!is_concurrent) - { - assert(count > 0u); - return in_seconds() / count; - } - // GCOVR_EXCL_STOP - - // Timer are always equal. - constexpr bool operator==(timer const &) const + /*!\name Comparison + * \{ + */ + //!\copydoc seqan::hibf::serial_timer::operator== + constexpr bool operator==(serial_timer const &) const { return true; } -private: - std::chrono::steady_clock::time_point start_{std::chrono::time_point::max()}; - std::chrono::steady_clock::time_point stop_{}; - - alignas(alignment) rep_t ticks{}; - alignas(alignment) rep_t max{}; - alignas(alignment) count_t count{}; - - void update_max(std::chrono::steady_clock::rep const value) - requires is_concurrent - { - for (std::chrono::steady_clock::rep previous_value = max; - previous_value < value && !max.compare_exchange_weak(previous_value, value, std::memory_order_relaxed);) - ; - } - - // GCOVR_EXCL_START - void update_max(std::chrono::steady_clock::rep const value) - requires (!is_concurrent) + //!\copydoc seqan::hibf::serial_timer::operator== + constexpr bool operator==(concurrent_timer const &) const { - max = std::max(max, value); + return true; } - // GCOVR_EXCL_STOP + //!\} }; -/*!\brief Alias for timer - * \ingroup hibf_build - */ -using serial_timer = timer; -/*!\brief Alias for timer - * \ingroup hibf_build - */ -using concurrent_timer = timer; - } // namespace seqan::hibf diff --git a/src/build/compute_kmers.cpp b/src/build/compute_kmers.cpp index 90f2e2b5..2be273d4 100644 --- a/src/build/compute_kmers.cpp +++ b/src/build/compute_kmers.cpp @@ -25,7 +25,7 @@ void compute_kmers(robin_hood::unordered_flat_set & kmers, build_data const & data, layout::layout::user_bin const & record) { - timer local_user_bin_io_timer{}; + serial_timer local_user_bin_io_timer{}; local_user_bin_io_timer.start(); data.config.input_fn(record.idx, insert_iterator{kmers}); local_user_bin_io_timer.stop(); diff --git a/src/build/construct_ibf.cpp b/src/build/construct_ibf.cpp index 0ee41b82..c15dd29b 100644 --- a/src/build/construct_ibf.cpp +++ b/src/build/construct_ibf.cpp @@ -47,7 +47,7 @@ seqan::hibf::interleaved_bloom_filter construct_ibf(robin_hood::unordered_flat_s : static_cast(std::ceil(bin_bits * data.fpr_correction[number_of_bins]))}; seqan::hibf::bin_count const bin_count{ibf_node.number_of_technical_bins}; - timer local_index_allocation_timer{}; + serial_timer local_index_allocation_timer{}; local_index_allocation_timer.start(); seqan::hibf::interleaved_bloom_filter ibf{bin_count, bin_size, diff --git a/src/build/insert_into_ibf.cpp b/src/build/insert_into_ibf.cpp index efe85c35..b0840552 100644 --- a/src/build/insert_into_ibf.cpp +++ b/src/build/insert_into_ibf.cpp @@ -30,12 +30,12 @@ void insert_into_ibf(robin_hood::unordered_flat_set const & kmers, size_t const number_of_bins, size_t const bin_index, seqan::hibf::interleaved_bloom_filter & ibf, - timer & fill_ibf_timer) + concurrent_timer & fill_ibf_timer) { size_t const chunk_size = divide_and_ceil(kmers.size(), number_of_bins); size_t chunk_number{}; - timer local_fill_ibf_timer{}; + serial_timer local_fill_ibf_timer{}; local_fill_ibf_timer.start(); for (auto chunk : kmers | seqan::stl::views::chunk(chunk_size)) { @@ -56,13 +56,13 @@ void insert_into_ibf(build_data const & data, auto const bin_index = seqan::hibf::bin_index{static_cast(record.storage_TB_id)}; std::vector values; - timer local_user_bin_io_timer{}; + serial_timer local_user_bin_io_timer{}; local_user_bin_io_timer.start(); data.config.input_fn(record.idx, insert_iterator{values}); local_user_bin_io_timer.stop(); data.user_bin_io_timer += local_user_bin_io_timer; - timer local_fill_ibf_timer{}; + serial_timer local_fill_ibf_timer{}; local_fill_ibf_timer.start(); for (auto && value : values) ibf.emplace(value, bin_index); diff --git a/test/unit/hibf/CMakeLists.txt b/test/unit/hibf/CMakeLists.txt index 8100e5a2..ae843de0 100644 --- a/test/unit/hibf/CMakeLists.txt +++ b/test/unit/hibf/CMakeLists.txt @@ -9,3 +9,4 @@ hibf_test (config_test.cpp) hibf_test (hierarchical_interleaved_bloom_filter_test.cpp) hibf_test (interleaved_bloom_filter_test.cpp) hibf_test (print_test.cpp) +hibf_test (timer_test.cpp) diff --git a/test/unit/hibf/timer_test.cpp b/test/unit/hibf/timer_test.cpp new file mode 100644 index 00000000..d25aae97 --- /dev/null +++ b/test/unit/hibf/timer_test.cpp @@ -0,0 +1,125 @@ +// SPDX-FileCopyrightText: 2006-2023, Knut Reinert & Freie Universität Berlin +// SPDX-FileCopyrightText: 2016-2023, Knut Reinert & MPI für molekulare Genetik +// SPDX-License-Identifier: BSD-3-Clause + +#include + +#include +#include + +#include + +static inline void waste_time() +{ + using namespace std::chrono_literals; + std::this_thread::sleep_for(1ms); +} + +template +using timer_test = ::testing::Test; + +using test_types = ::testing::Types; + +TYPED_TEST_SUITE(timer_test, test_types); + +TYPED_TEST(timer_test, concepts) +{ + EXPECT_TRUE(std::is_default_constructible_v); + EXPECT_TRUE(std::is_copy_constructible_v); + EXPECT_TRUE(std::is_move_constructible_v); + EXPECT_TRUE(std::is_copy_assignable_v); + EXPECT_TRUE(std::is_move_assignable_v); + EXPECT_TRUE(std::is_destructible_v); +} + +#ifndef NDEBUG +TYPED_TEST(timer_test, assertions) +{ + TypeParam timer{}; + EXPECT_DEATH(timer.stop(), "stop_point >= start_point"); + EXPECT_DEATH(timer.avg_in_seconds(), "count(\\.load\\(\\))? > 0u"); +} +#endif + +TYPED_TEST(timer_test, in_seconds) +{ + TypeParam timer{}; + EXPECT_EQ(timer.in_seconds(), 0.0); + timer.start(); + waste_time(); + timer.stop(); + double const first_time = timer.in_seconds(); + EXPECT_GE(first_time, 0.001); + + timer.start(); + waste_time(); + timer.stop(); + double const second_time = timer.in_seconds(); + EXPECT_GE(second_time, 0.002); + EXPECT_GT(second_time, first_time); +} + +TYPED_TEST(timer_test, max_in_seconds) +{ + TypeParam timer{}; + timer.start(); + timer.stop(); + double const first_max = timer.max_in_seconds(); + EXPECT_GE(first_max, 0.0); + EXPECT_EQ(first_max, timer.in_seconds()); + + timer.start(); + waste_time(); + timer.stop(); + double const second_max = timer.max_in_seconds(); + EXPECT_GT(second_max, first_max); +} + +TYPED_TEST(timer_test, avg_in_seconds) +{ + TypeParam timer{}; + timer.start(); + timer.stop(); + double const first_avg = timer.avg_in_seconds(); + EXPECT_GE(first_avg, 0.0); + EXPECT_EQ(first_avg, timer.in_seconds()); + + timer.start(); + waste_time(); + timer.stop(); + double const second_avg = timer.avg_in_seconds(); + EXPECT_EQ(second_avg, timer.in_seconds() / 2.0); + EXPECT_GT(second_avg, first_avg); +} + +TYPED_TEST(timer_test, add) +{ + TypeParam timer{}; + + seqan::hibf::serial_timer timer2{}; + timer2.start(); + waste_time(); + timer2.stop(); + + seqan::hibf::concurrent_timer timer3{}; + timer3.start(); + waste_time(); + timer3.stop(); + + EXPECT_EQ(timer.in_seconds(), 0.0); + + timer += timer2; + EXPECT_GE(timer.in_seconds(), 0.001); + + timer += timer3; + EXPECT_GE(timer.in_seconds(), 0.002); +} + +TYPED_TEST(timer_test, comparison) +{ + TypeParam timer1{}; + seqan::hibf::serial_timer timer2{}; + seqan::hibf::concurrent_timer timer3{}; + EXPECT_TRUE(timer1 == timer2); + EXPECT_TRUE(timer1 == timer3); +}