From 0f8e5a146563d1f245f8f62cb931dc1e0b55de2f Mon Sep 17 00:00:00 2001 From: Fernando Sahmkow Date: Sat, 8 Feb 2020 12:48:57 -0400 Subject: Tests: Add base tests to host timing --- src/common/thread.h | 4 +- src/core/host_timing.cpp | 101 +++++++++++++++++---------- src/core/host_timing.h | 30 +++++++-- src/tests/CMakeLists.txt | 1 + src/tests/core/host_timing.cpp | 150 +++++++++++++++++++++++++++++++++++++++++ 5 files changed, 243 insertions(+), 43 deletions(-) create mode 100644 src/tests/core/host_timing.cpp (limited to 'src') diff --git a/src/common/thread.h b/src/common/thread.h index 2fc071685..127cc7e23 100644 --- a/src/common/thread.h +++ b/src/common/thread.h @@ -9,6 +9,7 @@ #include #include #include +#include "common/common_types.h" namespace Common { @@ -28,8 +29,7 @@ public: is_set = false; } - template - bool WaitFor(const std::chrono::duration& time) { + bool WaitFor(const std::chrono::nanoseconds& time) { std::unique_lock lk{mutex}; if (!condvar.wait_for(lk, time, [this] { return is_set; })) return false; diff --git a/src/core/host_timing.cpp b/src/core/host_timing.cpp index c02f571c6..d9514b2c5 100644 --- a/src/core/host_timing.cpp +++ b/src/core/host_timing.cpp @@ -10,7 +10,6 @@ #include #include "common/assert.h" -#include "common/thread.h" #include "core/core_timing_util.h" namespace Core::HostTiming { @@ -47,39 +46,55 @@ void CoreTiming::Initialize() { event_fifo_id = 0; const auto empty_timed_callback = [](u64, s64) {}; ev_lost = CreateEvent("_lost_event", empty_timed_callback); - start_time = std::chrono::system_clock::now(); + start_time = std::chrono::steady_clock::now(); timer_thread = std::make_unique(ThreadEntry, std::ref(*this)); } void CoreTiming::Shutdown() { - std::unique_lock guard(inner_mutex); + paused = true; shutting_down = true; - if (!is_set) { - is_set = true; - condvar.notify_one(); - } - inner_mutex.unlock(); + event.Set(); timer_thread->join(); ClearPendingEvents(); + timer_thread.reset(); + has_started = false; +} + +void CoreTiming::Pause(bool is_paused) { + paused = is_paused; +} + +void CoreTiming::SyncPause(bool is_paused) { + if (is_paused == paused && paused_set == paused) { + return; + } + Pause(is_paused); + event.Set(); + while (paused_set != is_paused); +} + +bool CoreTiming::IsRunning() { + return !paused_set; +} + +bool CoreTiming::HasPendingEvents() { + return !(wait_set && event_queue.empty()); } void CoreTiming::ScheduleEvent(s64 ns_into_future, const std::shared_ptr& event_type, u64 userdata) { - std::lock_guard guard{inner_mutex}; + basic_lock.lock(); const u64 timeout = static_cast(GetGlobalTimeNs().count() + ns_into_future); event_queue.emplace_back(Event{timeout, event_fifo_id++, userdata, event_type}); std::push_heap(event_queue.begin(), event_queue.end(), std::greater<>()); - if (!is_set) { - is_set = true; - condvar.notify_one(); - } + basic_lock.unlock(); + event.Set(); } void CoreTiming::UnscheduleEvent(const std::shared_ptr& event_type, u64 userdata) { - std::lock_guard guard{inner_mutex}; - + basic_lock.lock(); const auto itr = std::remove_if(event_queue.begin(), event_queue.end(), [&](const Event& e) { return e.type.lock().get() == event_type.get() && e.userdata == userdata; }); @@ -89,6 +104,7 @@ void CoreTiming::UnscheduleEvent(const std::shared_ptr& event_type, u event_queue.erase(itr, event_queue.end()); std::make_heap(event_queue.begin(), event_queue.end(), std::greater<>()); } + basic_lock.unlock(); } u64 CoreTiming::GetCPUTicks() const { @@ -106,7 +122,7 @@ void CoreTiming::ClearPendingEvents() { } void CoreTiming::RemoveEvent(const std::shared_ptr& event_type) { - std::lock_guard guard{inner_mutex}; + basic_lock.lock(); const auto itr = std::remove_if(event_queue.begin(), event_queue.end(), [&](const Event& e) { return e.type.lock().get() == event_type.get(); @@ -117,43 +133,54 @@ void CoreTiming::RemoveEvent(const std::shared_ptr& event_type) { event_queue.erase(itr, event_queue.end()); std::make_heap(event_queue.begin(), event_queue.end(), std::greater<>()); } + basic_lock.unlock(); } void CoreTiming::Advance() { - while (true) { - std::unique_lock guard(inner_mutex); - - global_timer = GetGlobalTimeNs().count(); - - while (!event_queue.empty() && event_queue.front().time <= global_timer) { - Event evt = std::move(event_queue.front()); - std::pop_heap(event_queue.begin(), event_queue.end(), std::greater<>()); - event_queue.pop_back(); - inner_mutex.unlock(); + has_started = true; + while (!shutting_down) { + while (!paused) { + paused_set = false; + basic_lock.lock(); + global_timer = GetGlobalTimeNs().count(); + + while (!event_queue.empty() && event_queue.front().time <= global_timer) { + Event evt = std::move(event_queue.front()); + std::pop_heap(event_queue.begin(), event_queue.end(), std::greater<>()); + event_queue.pop_back(); + basic_lock.unlock(); + + if (auto event_type{evt.type.lock()}) { + event_type->callback(evt.userdata, global_timer - evt.time); + } + + basic_lock.lock(); + } - if (auto event_type{evt.type.lock()}) { - event_type->callback(evt.userdata, global_timer - evt.time); + if (!event_queue.empty()) { + std::chrono::nanoseconds next_time = std::chrono::nanoseconds(event_queue.front().time - global_timer); + basic_lock.unlock(); + event.WaitFor(next_time); + } else { + basic_lock.unlock(); + wait_set = true; + event.Wait(); } - inner_mutex.lock(); - } - auto next_time = std::chrono::nanoseconds(event_queue.front().time - global_timer); - condvar.wait_for(guard, next_time, [this] { return is_set; }); - is_set = false; - if (shutting_down) { - break; + wait_set = false; } + paused_set = true; } } std::chrono::nanoseconds CoreTiming::GetGlobalTimeNs() const { - sys_time_point current = std::chrono::system_clock::now(); + sys_time_point current = std::chrono::steady_clock::now(); auto elapsed = current - start_time; return std::chrono::duration_cast(elapsed); } std::chrono::microseconds CoreTiming::GetGlobalTimeUs() const { - sys_time_point current = std::chrono::system_clock::now(); + sys_time_point current = std::chrono::steady_clock::now(); auto elapsed = current - start_time; return std::chrono::duration_cast(elapsed); } diff --git a/src/core/host_timing.h b/src/core/host_timing.h index a3a32e087..1d053a7fa 100644 --- a/src/core/host_timing.h +++ b/src/core/host_timing.h @@ -14,13 +14,15 @@ #include #include "common/common_types.h" +#include "common/spin_lock.h" +#include "common/thread.h" #include "common/threadsafe_queue.h" namespace Core::HostTiming { /// A callback that may be scheduled for a particular core timing event. using TimedCallback = std::function; -using sys_time_point = std::chrono::time_point; +using sys_time_point = std::chrono::time_point; /// Contains the characteristics of a particular event. struct EventType { @@ -63,6 +65,23 @@ public: /// Tears down all timing related functionality. void Shutdown(); + /// Pauses/Unpauses the execution of the timer thread. + void Pause(bool is_paused); + + /// Pauses/Unpauses the execution of the timer thread and waits until paused. + void SyncPause(bool is_paused); + + /// Checks if core timing is running. + bool IsRunning(); + + /// Checks if the timer thread has started. + bool HasStarted() { + return has_started; + } + + /// Checks if there are any pending time events. + bool HasPendingEvents(); + /// Schedules an event in core timing void ScheduleEvent(s64 ns_into_future, const std::shared_ptr& event_type, u64 userdata = 0); @@ -107,11 +126,14 @@ private: u64 event_fifo_id = 0; std::shared_ptr ev_lost; - bool is_set = false; - std::condition_variable condvar; - std::mutex inner_mutex; + Common::Event event{}; + Common::SpinLock basic_lock{}; std::unique_ptr timer_thread; + std::atomic paused{}; + std::atomic paused_set{}; + std::atomic wait_set{}; std::atomic shutting_down{}; + std::atomic has_started{}; }; /// Creates a core timing event with the given name and callback. diff --git a/src/tests/CMakeLists.txt b/src/tests/CMakeLists.txt index 47ef30aa9..3f750b51c 100644 --- a/src/tests/CMakeLists.txt +++ b/src/tests/CMakeLists.txt @@ -8,6 +8,7 @@ add_executable(tests core/arm/arm_test_common.cpp core/arm/arm_test_common.h core/core_timing.cpp + core/host_timing.cpp tests.cpp ) diff --git a/src/tests/core/host_timing.cpp b/src/tests/core/host_timing.cpp new file mode 100644 index 000000000..ca9c8e50a --- /dev/null +++ b/src/tests/core/host_timing.cpp @@ -0,0 +1,150 @@ +// Copyright 2016 Dolphin Emulator Project / 2017 Dolphin Emulator Project +// Licensed under GPLv2+ +// Refer to the license.txt file included. + +#include + +#include +#include +#include +#include +#include + +#include "common/file_util.h" +#include "core/core.h" +#include "core/host_timing.h" + +// Numbers are chosen randomly to make sure the correct one is given. +static constexpr std::array CB_IDS{{42, 144, 93, 1026, UINT64_C(0xFFFF7FFFF7FFFF)}}; +static constexpr int MAX_SLICE_LENGTH = 10000; // Copied from CoreTiming internals +static constexpr std::array calls_order{{2,0,1,4,3}}; +static std::array delays{}; + +static std::bitset callbacks_ran_flags; +static u64 expected_callback = 0; +static s64 lateness = 0; + +template +void HostCallbackTemplate(u64 userdata, s64 nanoseconds_late) { + static_assert(IDX < CB_IDS.size(), "IDX out of range"); + callbacks_ran_flags.set(IDX); + REQUIRE(CB_IDS[IDX] == userdata); + REQUIRE(CB_IDS[IDX] == CB_IDS[calls_order[expected_callback]]); + delays[IDX] = nanoseconds_late; + ++expected_callback; +} + +static u64 callbacks_done = 0; + +struct ScopeInit final { + ScopeInit() { + core_timing.Initialize(); + } + ~ScopeInit() { + core_timing.Shutdown(); + } + + Core::HostTiming::CoreTiming core_timing; +}; + +TEST_CASE("HostTiming[BasicOrder]", "[core]") { + ScopeInit guard; + auto& core_timing = guard.core_timing; + std::vector> events; + events.resize(5); + events[0] = + Core::HostTiming::CreateEvent("callbackA", HostCallbackTemplate<0>); + events[1] = + Core::HostTiming::CreateEvent("callbackB", HostCallbackTemplate<1>); + events[2] = + Core::HostTiming::CreateEvent("callbackC", HostCallbackTemplate<2>); + events[3] = + Core::HostTiming::CreateEvent("callbackD", HostCallbackTemplate<3>); + events[4] = + Core::HostTiming::CreateEvent("callbackE", HostCallbackTemplate<4>); + + expected_callback = 0; + + core_timing.SyncPause(true); + + u64 one_micro = 1000U; + for (std::size_t i = 0; i < events.size(); i++) { + u64 order = calls_order[i]; + core_timing.ScheduleEvent(i*one_micro + 100U, events[order], CB_IDS[order]); + } + /// test pause + REQUIRE(callbacks_ran_flags.none()); + + core_timing.Pause(false); // No need to sync + + while (core_timing.HasPendingEvents()); + + REQUIRE(callbacks_ran_flags.all()); + + for (std::size_t i = 0; i < delays.size(); i++) { + const double delay = static_cast(delays[i]); + const double micro = delay / 1000.0f; + const double mili = micro / 1000.0f; + printf("HostTimer Pausing Delay[%zu]: %.3f %.6f\n", i, micro, mili); + } +} + +#pragma optimize("", off) +u64 TestTimerSpeed(Core::HostTiming::CoreTiming& core_timing) { + u64 start = core_timing.GetGlobalTimeNs().count(); + u64 placebo = 0; + for (std::size_t i = 0; i < 1000; i++) { + placebo += core_timing.GetGlobalTimeNs().count(); + } + u64 end = core_timing.GetGlobalTimeNs().count(); + return (end - start); +} +#pragma optimize("", on) + +TEST_CASE("HostTiming[BasicOrderNoPausing]", "[core]") { + ScopeInit guard; + auto& core_timing = guard.core_timing; + std::vector> events; + events.resize(5); + events[0] = + Core::HostTiming::CreateEvent("callbackA", HostCallbackTemplate<0>); + events[1] = + Core::HostTiming::CreateEvent("callbackB", HostCallbackTemplate<1>); + events[2] = + Core::HostTiming::CreateEvent("callbackC", HostCallbackTemplate<2>); + events[3] = + Core::HostTiming::CreateEvent("callbackD", HostCallbackTemplate<3>); + events[4] = + Core::HostTiming::CreateEvent("callbackE", HostCallbackTemplate<4>); + + core_timing.SyncPause(true); + core_timing.SyncPause(false); + + expected_callback = 0; + + u64 start = core_timing.GetGlobalTimeNs().count(); + u64 one_micro = 1000U; + for (std::size_t i = 0; i < events.size(); i++) { + u64 order = calls_order[i]; + core_timing.ScheduleEvent(i*one_micro + 100U, events[order], CB_IDS[order]); + } + u64 end = core_timing.GetGlobalTimeNs().count(); + const double scheduling_time = static_cast(end - start); + const double timer_time = static_cast(TestTimerSpeed(core_timing)); + + while (core_timing.HasPendingEvents()); + + REQUIRE(callbacks_ran_flags.all()); + + for (std::size_t i = 0; i < delays.size(); i++) { + const double delay = static_cast(delays[i]); + const double micro = delay / 1000.0f; + const double mili = micro / 1000.0f; + printf("HostTimer No Pausing Delay[%zu]: %.3f %.6f\n", i, micro, mili); + } + + const double micro = scheduling_time / 1000.0f; + const double mili = micro / 1000.0f; + printf("HostTimer No Pausing Scheduling Time: %.3f %.6f\n", micro, mili); + printf("HostTimer No Pausing Timer Time: %.3f %.6f\n", timer_time / 1000.f, timer_time / 1000000.f); +} -- cgit v1.2.3