From 7e961817b2a6ed9a4338bc48abbc279f09c025f5 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Henrik=20Rydg=C3=A5rd?= Date: Sat, 17 Sep 2022 12:14:41 +0200 Subject: [PATCH] Implement a simple event profiler view. --- CMakeLists.txt | 2 + Common/Common.vcxproj | 2 + Common/Common.vcxproj.filters | 6 + Common/GPU/Vulkan/VulkanDebug.cpp | 1 - Common/GPU/Vulkan/VulkanFrameData.h | 3 + Common/GPU/Vulkan/VulkanQueueRunner.cpp | 4 + Common/GPU/Vulkan/VulkanRenderManager.cpp | 36 +++- Common/GPU/Vulkan/VulkanRenderManager.h | 3 + Common/Input/InputState.h | 2 + Common/Profiler/EventStream.cpp | 114 +++++++++++ Common/Profiler/EventStream.h | 119 +++++++++++ Common/TimeUtil.h | 32 +++ Common/UI/Context.cpp | 7 +- Common/UI/Context.h | 4 + Common/UI/View.h | 3 +- Common/UI/ViewGroup.h | 12 +- Core/Config.h | 1 + UI/DevScreens.cpp | 5 + UI/DevScreens.h | 1 + UI/EmuScreen.cpp | 11 + UI/ProfilerDraw.cpp | 234 ++++++++++++++++++++++ UI/ProfilerDraw.h | 44 +++- Windows/MainWindow.cpp | 7 + android/jni/Android.mk | 1 + libretro/Makefile.common | 1 + unittest/TestThreadManager.cpp | 4 +- 26 files changed, 637 insertions(+), 22 deletions(-) create mode 100644 Common/Profiler/EventStream.cpp create mode 100644 Common/Profiler/EventStream.h diff --git a/CMakeLists.txt b/CMakeLists.txt index cc31004ebc..7af3e586d1 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -659,6 +659,8 @@ add_library(Common STATIC Common/Net/WebsocketServer.h Common/Profiler/Profiler.cpp Common/Profiler/Profiler.h + Common/Profiler/EventStream.cpp + Common/Profiler/EventStream.h Common/Render/TextureAtlas.cpp Common/Render/TextureAtlas.h Common/Render/DrawBuffer.cpp diff --git a/Common/Common.vcxproj b/Common/Common.vcxproj index d232c01534..fe2c405c1a 100644 --- a/Common/Common.vcxproj +++ b/Common/Common.vcxproj @@ -466,6 +466,7 @@ + @@ -886,6 +887,7 @@ + diff --git a/Common/Common.vcxproj.filters b/Common/Common.vcxproj.filters index 991b03a71f..6cf34049df 100644 --- a/Common/Common.vcxproj.filters +++ b/Common/Common.vcxproj.filters @@ -422,6 +422,9 @@ GPU\Vulkan + + Profiler + @@ -797,6 +800,9 @@ GPU\Vulkan + + Profiler + diff --git a/Common/GPU/Vulkan/VulkanDebug.cpp b/Common/GPU/Vulkan/VulkanDebug.cpp index b52e4396cb..83b3d974c0 100644 --- a/Common/GPU/Vulkan/VulkanDebug.cpp +++ b/Common/GPU/Vulkan/VulkanDebug.cpp @@ -93,4 +93,3 @@ VKAPI_ATTR VkBool32 VKAPI_CALL VulkanDebugUtilsCallback( // keep that behavior here. return false; } - diff --git a/Common/GPU/Vulkan/VulkanFrameData.h b/Common/GPU/Vulkan/VulkanFrameData.h index 9fdd865ebf..6a0f4316d8 100644 --- a/Common/GPU/Vulkan/VulkanFrameData.h +++ b/Common/GPU/Vulkan/VulkanFrameData.h @@ -6,6 +6,7 @@ #include #include "Common/GPU/Vulkan/VulkanContext.h" +#include "Common/Profiler/EventStream.h" enum { MAX_TIMESTAMP_QUERIES = 128, @@ -74,6 +75,8 @@ struct FrameData { // Profiling. QueueProfileContext profile; bool profilingEnabled_; + EventStream *mainThreadEvents; + EventStream *renderThreadEvents; void Init(VulkanContext *vulkan, int index); void Destroy(VulkanContext *vulkan); diff --git a/Common/GPU/Vulkan/VulkanQueueRunner.cpp b/Common/GPU/Vulkan/VulkanQueueRunner.cpp index 542ba7a1e2..f1adde1858 100644 --- a/Common/GPU/Vulkan/VulkanQueueRunner.cpp +++ b/Common/GPU/Vulkan/VulkanQueueRunner.cpp @@ -6,6 +6,8 @@ #include "Common/Log.h" #include "Common/TimeUtil.h" +#include "Common/Profiler/EventStream.h" + using namespace PPSSPP_VK; // Debug help: adb logcat -s DEBUG PPSSPPNativeActivity PPSSPP NativeGLView NativeRenderer NativeSurfaceView PowerSaveModeReceiver InputDeviceState @@ -555,6 +557,8 @@ void VulkanQueueRunner::PreprocessSteps(std::vector &steps) { } void VulkanQueueRunner::RunSteps(std::vector &steps, FrameData &frameData, FrameDataShared &frameDataShared) { + EventScope scope(frameData.renderThreadEvents, "run_steps", EventStream::EventType::COMPUTE); + QueueProfileContext *profile = frameData.profilingEnabled_ ? &frameData.profile : nullptr; if (profile) diff --git a/Common/GPU/Vulkan/VulkanRenderManager.cpp b/Common/GPU/Vulkan/VulkanRenderManager.cpp index a666a830de..7ba9e6f113 100644 --- a/Common/GPU/Vulkan/VulkanRenderManager.cpp +++ b/Common/GPU/Vulkan/VulkanRenderManager.cpp @@ -13,6 +13,8 @@ #include "Common/Thread/ThreadUtil.h" +#include "Common/Profiler/EventStream.h" + #if 0 // def _DEBUG #define VLOG(...) NOTICE_LOG(G3D, __VA_ARGS__) #else @@ -292,12 +294,18 @@ void CreateImage(VulkanContext *vulkan, VkCommandBuffer cmd, VKRImage &img, int } VulkanRenderManager::VulkanRenderManager(VulkanContext *vulkan) : vulkan_(vulkan), queueRunner_(vulkan) { + mainThreadEvents_ = g_eventStreamManager.Get("render_main"); + renderThreadEvents_ = g_eventStreamManager.Get("render_submit"); + inflightFramesAtStart_ = vulkan_->GetInflightFrames(); frameDataShared_.Init(vulkan); for (int i = 0; i < inflightFramesAtStart_; i++) { frameData_[i].Init(vulkan, i); + + frameData_[i].mainThreadEvents = mainThreadEvents_; + frameData_[i].renderThreadEvents = renderThreadEvents_; } queueRunner_.CreateDeviceObjects(); @@ -472,6 +480,7 @@ void VulkanRenderManager::ThreadFunc() { // Pop a task of the queue and execute it. VKRRenderThreadTask task; { + EventScope scope(renderThreadEvents_, "idle", EventStream::EventType::BLOCK); std::unique_lock lock(pushMutex_); while (renderThreadQueue_.empty()) { pushCondVar_.wait(lock); @@ -480,6 +489,7 @@ void VulkanRenderManager::ThreadFunc() { renderThreadQueue_.pop(); } + renderThreadEvents_->SetFrameId(task.frame); // Oh, we got a task! We can now have pushMutex_ unlocked, allowing the host to // push more work when it feels like it, and just start working. if (task.runType == VKRRunType::EXIT) { @@ -504,24 +514,29 @@ void VulkanRenderManager::BeginFrame(bool enableProfiling, bool enableLogProfile int curFrame = vulkan_->GetCurFrame(); FrameData &frameData = frameData_[curFrame]; + mainThreadEvents_->SetFrameId(curFrame); + VLOG("PUSH: Fencing %d", curFrame); // Makes sure the submission from the previous time around has happened. Otherwise // we are not allowed to wait from another thread here.. { - std::unique_lock lock(frameData.fenceMutex); - while (!frameData.readyForFence) { - frameData.fenceCondVar.wait(lock); + EventScope scope(mainThreadEvents_, "fence", EventStream::EventType::BLOCK); + { + std::unique_lock lock(frameData.fenceMutex); + while (!frameData.readyForFence) { + frameData.fenceCondVar.wait(lock); + } + frameData.readyForFence = false; } - frameData.readyForFence = false; - } - // This must be the very first Vulkan call we do in a new frame. - // Makes sure the very last command buffer from the frame before the previous has been fully executed. - if (vkWaitForFences(device, 1, &frameData.fence, true, UINT64_MAX) == VK_ERROR_DEVICE_LOST) { - _assert_msg_(false, "Device lost in vkWaitForFences"); + // This must be the very first Vulkan call we do in a new frame. + // Makes sure the very last command buffer from the frame before the previous has been fully executed. + if (vkWaitForFences(device, 1, &frameData.fence, true, UINT64_MAX) == VK_ERROR_DEVICE_LOST) { + _assert_msg_(false, "Device lost in vkWaitForFences"); + } + vkResetFences(device, 1, &frameData.fence); } - vkResetFences(device, 1, &frameData.fence); // Can't set this until after the fence. frameData.profilingEnabled_ = enableProfiling; @@ -1172,6 +1187,7 @@ void VulkanRenderManager::Finish() { FrameData &frameData = frameData_[curFrame]; { + EventScope scope(mainThreadEvents_, "push", EventStream::EventType::COMPUTE); VLOG("PUSH: Frame[%d]", curFrame); VKRRenderThreadTask task; task.frame = curFrame; diff --git a/Common/GPU/Vulkan/VulkanRenderManager.h b/Common/GPU/Vulkan/VulkanRenderManager.h index ed9f0d16e5..9d4e7e0c7d 100644 --- a/Common/GPU/Vulkan/VulkanRenderManager.h +++ b/Common/GPU/Vulkan/VulkanRenderManager.h @@ -529,4 +529,7 @@ private: // pipelines to check and possibly create at the end of the current render pass. std::vector pipelinesToCheck_; + + EventStream *mainThreadEvents_; + EventStream *renderThreadEvents_; }; diff --git a/Common/Input/InputState.h b/Common/Input/InputState.h index faa6416e30..c5ed420c5c 100644 --- a/Common/Input/InputState.h +++ b/Common/Input/InputState.h @@ -98,6 +98,7 @@ public: } }; +// Used for both touch and mouse. enum { TOUCH_MOVE = 1 << 0, TOUCH_DOWN = 1 << 1, @@ -106,6 +107,7 @@ enum { TOUCH_WHEEL = 1 << 4, // Scrollwheel event. Usually only affects Y but can potentially affect X. TOUCH_MOUSE = 1 << 5, // Identifies that this touch event came from a mouse TOUCH_RELEASE_ALL = 1 << 6, // Useful for app focus switches when events may be lost. + TOUCH_HOVER_MOVE = 1 << 7, // Same as move but also happens when no button is pressed. Only works for mice, of course. // These are the Android getToolType() codes, shifted by 10. TOUCH_TOOL_MASK = 7 << 10, diff --git a/Common/Profiler/EventStream.cpp b/Common/Profiler/EventStream.cpp new file mode 100644 index 0000000000..f7009ee732 --- /dev/null +++ b/Common/Profiler/EventStream.cpp @@ -0,0 +1,114 @@ +#include +#include + +#include "EventStream.h" + +// Impl to avoid including (or similar) in the header. +struct EventStreamManagerImpl { + EventStream *Get(const char *identifier); + + std::vector> streams; +}; + +EventStreamManager::EventStreamManager() : impl_(new EventStreamManagerImpl) {} +EventStreamManager::~EventStreamManager() { delete impl_; } + +EventStreamManager g_eventStreamManager; + +void EventStreamManager::GarbageCollect(Instant before) { + for (auto &iter : impl_->streams) { + iter->GarbageCollect(before); + } +} + +EventStream *EventStreamManager::Get(const char *identifier) { + for (auto &iter : impl_->streams) { + if (!strcmp(identifier, iter->Identifier())) + return iter.get(); + } + + EventStream *stream = new EventStream(identifier); + impl_->streams.push_back(std::unique_ptr(stream)); + return stream; +} + +EventStream *EventStreamManager::GetByIndex(size_t index) { + if (index < 0 || index >= impl_->streams.size()) { + return nullptr; + } else { + return impl_->streams[index].get(); + } +} + +size_t EventStreamManager::NumStreams() { + return impl_->streams.size(); +} + +// Matches the GetAll order. +size_t NumStreams(); + +std::vector EventStreamManager::GetAll() { + std::vector vec; + for (auto &iter : impl_->streams) { + vec.push_back(iter.get()); + } + return vec; +} + +std::vector EventStream::GetEventRange(Instant startTime, Instant endTime, int64_t *firstEventId) { + // Search backwards to the start. Since we keep history and are usually looking somewhere + // near the end, this will usually be fast enough, no need for acceleration structures. + std::lock_guard guard(lock_); + int i; + for (i = (int)events_.size() - 1; i >= 0; i--) { + if (events_[i].endTime < startTime) { + break; + } + } + + if (i < 0) { + return std::vector(); + } + + *firstEventId = i; + + std::vector outEvents; + for (int j = i; j < (int)events_.size(); j++) { + if (events_[j].startTime > endTime) { + // Reached the end. + break; + } + outEvents.push_back(events_[j]); + } + + return outEvents; +} + +int64_t EventStream::GetEventIdAt(Instant time) { + std::lock_guard guard(lock_); + int i; + for (i = (int)events_.size() - 1; i >= 0; i--) { + if (time >= events_[i].startTime && time < events_[i].endTime) { + return i; + } + } + return -1; +} + +void EventStream::GarbageCollect(Instant before) { + std::lock_guard guard(lock_); + + size_t i; + for (i = 0; i < events_.size(); i++) { + if (events_[i].startTime > before) { + break; + } + } + + if (i == 0) { + return; + } + + events_.erase(events_.begin(), events_.begin() + i); + offset_ += i; +} diff --git a/Common/Profiler/EventStream.h b/Common/Profiler/EventStream.h new file mode 100644 index 0000000000..d2992618c0 --- /dev/null +++ b/Common/Profiler/EventStream.h @@ -0,0 +1,119 @@ +#pragma once + +// Event streams. +// +// Used to visualize things over time. Will be a building block for the new built-in profiler, too. +// Does not yet support hiearchies of events properly, but will. + +#include +#include + +#include "Common/TimeUtil.h" + +struct EventStreamManagerImpl; +class EventStream; + +class EventStreamManager { +public: + EventStreamManager(); + ~EventStreamManager(); + + EventStream *Get(const char *identifier); + EventStream *GetByIndex(size_t index); // Matches the GetAll order. + size_t NumStreams(); + + void GarbageCollect(Instant before); + + void SetRunning(bool running) { running_ = running; } + bool IsRunning() const { return running_; } + + // For listing, visualization. + std::vector GetAll(); + +private: + EventStreamManagerImpl *impl_; +#ifdef _DEBUG + bool running_ = true; +#else + bool running_ = false; +#endif + + friend class EventStream; +}; + +extern EventStreamManager g_eventStreamManager; +class EventStream { +public: + enum class EventType : uint8_t { + BLOCK, + COMPUTE, + }; + + struct Event { + const char *name; + int frameId; + EventType type; + Instant startTime; + Instant endTime; + }; + + EventStream(const char *id) : identifier_(id) {} + + void SetFrameId(int frameId) { + frameId_ = frameId; + } + + int64_t Begin(const char *name, EventType type) { + if (!g_eventStreamManager.running_) + return -1; + + std::lock_guard guard(lock_); + Instant now = Instant::Now(); + events_.push_back(Event{ name, frameId_, type, now, now }); + return (int64_t)(offset_ + events_.size() - 1); + } + + void End(int64_t eventId) { + if (!g_eventStreamManager.running_ || eventId < 0) + return; + + std::lock_guard guard(lock_); + if ((size_t)eventId >= offset_) { + events_[(size_t)eventId - offset_].endTime = Instant::Now(); + } + } + + // Erases stored data older than the specified instant. Call from time to time. + // TODO: Go by frame ID instead? + void GarbageCollect(Instant before); + + // This always returns a linear sequence, so you can deduce the id of each event by adding the index to firstEventId. + std::vector GetEventRange(Instant start, Instant end, int64_t *firstEventId); + + int64_t GetEventIdAt(Instant time); + + const char *Identifier() const { return identifier_; } + +private: + const char *identifier_; + size_t offset_ = 0; + std::vector events_; + int frameId_ = 0; + + // TODO: Figure out how we can do this all without a mutex. + std::mutex lock_; +}; + +class EventScope { +public: + EventScope(EventStream *stream, const char *name, EventStream::EventType type) : stream_(stream) { + id_ = stream->Begin(name, type); + } + ~EventScope() { + stream_->End(id_); + } + +private: + EventStream *stream_; + size_t id_; +}; diff --git a/Common/TimeUtil.h b/Common/TimeUtil.h index 0faf6dac23..ada1af51ef 100644 --- a/Common/TimeUtil.h +++ b/Common/TimeUtil.h @@ -9,14 +9,46 @@ void sleep_ms(int ms); void GetTimeFormatted(char formattedTime[13]); // Rust-style Instant for clear and easy timing. +// TODO: Optimize to not convert to seconds until calling Elapsed (Now() should just store +// the raw time value from the functions, depending on platform). class Instant { public: + Instant() {} static Instant Now() { return Instant(time_now_d()); } double Elapsed() const { return time_now_d() - instantTime_; } + static Instant FromSeconds(double seconds) { + return Instant{ seconds }; + } + double ToSeconds() const { + return instantTime_; + } + static Instant FromSecondsAgo(double seconds) { + return Instant{ time_now_d() - seconds }; + } + double DifferenceInSeconds(const Instant &later) const { + return later.instantTime_ - instantTime_; + } + + Instant AddSeconds(double seconds) { + return Instant{ instantTime_ + seconds }; + } + + bool operator >(const Instant &other) const { + return instantTime_ > other.instantTime_; + } + bool operator <(const Instant &other) const { + return instantTime_ < other.instantTime_; + } + bool operator >=(const Instant &other) const { + return instantTime_ >= other.instantTime_; + } + bool operator <=(const Instant &other) const { + return instantTime_ <= other.instantTime_; + } private: explicit Instant(double initTime) : instantTime_(initTime) {} double instantTime_; diff --git a/Common/UI/Context.cpp b/Common/UI/Context.cpp index 21c687bd2b..bbe6c03ca8 100644 --- a/Common/UI/Context.cpp +++ b/Common/UI/Context.cpp @@ -299,7 +299,12 @@ void UIContext::FillRect(const UI::Drawable &drawable, const Bounds &bounds) { break; case UI::DRAW_NOTHING: break; - } + } +} + +void UIContext::VLine(float x, float y0, float y1, uint32_t color) { + UI::Drawable drawable(color); + FillRect(drawable, Bounds(x, y0, g_dpi_scale_x, y1 - y0)); } void UIContext::DrawImageVGradient(ImageID image, uint32_t color1, uint32_t color2, const Bounds &bounds) { diff --git a/Common/UI/Context.h b/Common/UI/Context.h index ac26ab0202..7717143b2f 100644 --- a/Common/UI/Context.h +++ b/Common/UI/Context.h @@ -86,7 +86,11 @@ public: void DrawTextShadow(const char *str, float x, float y, uint32_t color, int align = 0); void DrawTextRect(const char *str, const Bounds &bounds, uint32_t color, int align = 0); void DrawTextShadowRect(const char *str, const Bounds &bounds, uint32_t color, int align = 0); + + // Works even without unbinding the texture, unlike the raw primitives in DrawBuffer. void FillRect(const UI::Drawable &drawable, const Bounds &bounds); + void VLine(float x, float y0, float y1, uint32_t color); + void DrawImageVGradient(ImageID image, uint32_t color1, uint32_t color2, const Bounds &bounds); // in dps, like dp_xres and dp_yres diff --git a/Common/UI/View.h b/Common/UI/View.h index 0a78433073..49bf26f953 100644 --- a/Common/UI/View.h +++ b/Common/UI/View.h @@ -262,7 +262,7 @@ public: // Call this from UI thread EventReturn Dispatch(EventParams &e); - // This is suggested for use in most cases. Autobinds, allowing for neat syntax. + // Autobinds, allowing for reasonably neat syntax without lambdas. template T *Handle(T *thiz, EventReturn (T::* theCallback)(EventParams &e)) { Add(std::bind(theCallback, thiz, std::placeholders::_1)); @@ -270,6 +270,7 @@ public: } // Sometimes you have an already-bound function<>, just use this then. + // Also works fine for lambdas. void Add(std::function func); private: diff --git a/Common/UI/ViewGroup.h b/Common/UI/ViewGroup.h index 5b552c5f0f..8603b2253f 100644 --- a/Common/UI/ViewGroup.h +++ b/Common/UI/ViewGroup.h @@ -14,16 +14,16 @@ namespace UI { class AnchorTranslateTween; struct NeighborResult { - NeighborResult() : view(0), score(0) {} + NeighborResult() {} NeighborResult(View *v, float s) : view(v), score(s) {} - View *view; - float score; + View *view = nullptr; + float score = 0.0f; }; class ViewGroup : public View { public: - ViewGroup(LayoutParams *layoutParams = 0) : View(layoutParams) {} + ViewGroup(LayoutParams *layoutParams = nullptr) : View(layoutParams) {} virtual ~ViewGroup(); // Pass through external events to children. @@ -182,7 +182,7 @@ private: class LinearLayout : public ViewGroup { public: LinearLayout(Orientation orientation, LayoutParams *layoutParams = 0) - : ViewGroup(layoutParams), orientation_(orientation), defaultMargins_(0), spacing_(10) {} + : ViewGroup(layoutParams), orientation_(orientation), defaultMargins_(0) {} void Measure(const UIContext &dc, MeasureSpec horiz, MeasureSpec vert) override; void Layout() override; @@ -195,7 +195,7 @@ protected: Orientation orientation_; private: Margins defaultMargins_; - float spacing_; + float spacing_ = 10.0f; }; class LinearLayoutList : public LinearLayout { diff --git a/Core/Config.h b/Core/Config.h index 36ec3a760d..81ea8e3e17 100644 --- a/Core/Config.h +++ b/Core/Config.h @@ -487,6 +487,7 @@ public: // Volatile development settings bool bShowFrameProfiler; + bool bShowEventProfiler; bool bGpuLogProfiler; // Controls the Vulkan logging profiler (profiles textures uploads etc). // Various directories. Autoconfigured, not read from ini. diff --git a/UI/DevScreens.cpp b/UI/DevScreens.cpp index ce5bd3fada..e1345f05a5 100644 --- a/UI/DevScreens.cpp +++ b/UI/DevScreens.cpp @@ -97,6 +97,11 @@ void DevMenuScreen::CreatePopupContents(UI::ViewGroup *parent) { items->Add(new Choice(dev->T("Log View")))->OnClick.Handle(this, &DevMenuScreen::OnLogView); #endif items->Add(new Choice(dev->T("Logging Channels")))->OnClick.Handle(this, &DevMenuScreen::OnLogConfig); + items->Add(new CheckBox(&g_Config.bShowEventProfiler, dev->T("Event Profiler"), ""))->OnClick.Add([=](UI::EventParams &e) -> UI::EventReturn { + // TODO: Find a better way to cause parent screens to recreate its views. + NativeMessageReceived("recreateviews", ""); + return UI::EVENT_DONE; + }); items->Add(new Choice(sy->T("Developer Tools")))->OnClick.Handle(this, &DevMenuScreen::OnDeveloperTools); items->Add(new Choice(dev->T("Jit Compare")))->OnClick.Handle(this, &DevMenuScreen::OnJitCompare); items->Add(new Choice(dev->T("Shader Viewer")))->OnClick.Handle(this, &DevMenuScreen::OnShaderView); diff --git a/UI/DevScreens.h b/UI/DevScreens.h index 0df3d73ce3..356d0af541 100644 --- a/UI/DevScreens.h +++ b/UI/DevScreens.h @@ -216,4 +216,5 @@ private: }; void DrawProfile(UIContext &ui); +void DrawEventStreams(UIContext &ui); const char *GetCompilerABI(); diff --git a/UI/EmuScreen.cpp b/UI/EmuScreen.cpp index 14ee1ced6c..71c1dbf813 100644 --- a/UI/EmuScreen.cpp +++ b/UI/EmuScreen.cpp @@ -773,6 +773,13 @@ bool EmuScreen::key(const KeyInput &key) { } } + // Unconditionally pass through some keys to the UI. + if (g_Config.bShowEventProfiler) { + if (key.keyCode == NKCODE_EXT_MOUSEWHEEL_DOWN || key.keyCode == NKCODE_EXT_MOUSEWHEEL_UP) { + UIScreen::key(key); + } + } + return controlMapper_.Key(key, &pauseTrigger_); } @@ -833,10 +840,14 @@ void EmuScreen::CreateViews() { // Devices without a back button like iOS need an on-screen touch back button. bool showPauseButton = !System_GetPropertyBool(SYSPROP_HAS_BACK_BUTTON) || g_Config.bShowTouchPause; + // Root is an anchor layout. root_ = CreatePadLayout(bounds.w, bounds.h, &pauseTrigger_, showPauseButton, &controlMapper_); if (g_Config.bShowDeveloperMenu) { root_->Add(new Button(dev->T("DevMenu")))->OnClick.Handle(this, &EmuScreen::OnDevTools); } + if (g_Config.bShowEventProfiler) { + root_->Add(new EventProfilerView(new AnchorLayoutParams(10, 60.0, 10.0, 60.0, false))); + } LinearLayout *buttons = new LinearLayout(Orientation::ORIENT_HORIZONTAL, new AnchorLayoutParams(bounds.centerX(), NONE, NONE, 60, true)); buttons->SetSpacing(20.0f); diff --git a/UI/ProfilerDraw.cpp b/UI/ProfilerDraw.cpp index aa5727fefe..cce60bee58 100644 --- a/UI/ProfilerDraw.cpp +++ b/UI/ProfilerDraw.cpp @@ -16,12 +16,18 @@ // https://github.com/hrydgard/ppsspp and http://www.ppsspp.org/. #include +#include #include +#include "Common/Log.h" #include "Common/Render/DrawBuffer.h" #include "Common/UI/Context.h" #include "Common/UI/View.h" #include "Common/Profiler/Profiler.h" +#include "Common/Profiler/EventStream.h" +#include "Common/TimeUtil.h" + +#include "UI/ProfilerDraw.h" #ifdef USE_PROFILER static const uint32_t nice_colors[] = { @@ -203,3 +209,231 @@ void DrawProfile(UIContext &ui) { lastMaxVal = lastMaxVal * 0.95f + maxVal * 0.05f; #endif } + +EventProfilerView::EventProfilerView(UI::LayoutParams *layoutParams) : UI::AnchorLayout(layoutParams) { + using namespace UI; + + LinearLayout *buttonRow = new LinearLayout(UI::ORIENT_HORIZONTAL, new AnchorLayoutParams(10.0f, NONE, NONE, 10.0f)); + Add(buttonRow); + + // Can create buttons and stuff here, I think. + // Let's place these at the bottom of the screen to be out of the way for now. will do something better later. + buttonRow->Add(new Button("Pause"))->OnClick.Add([=](UI::EventParams &) { + g_eventStreamManager.SetRunning(!g_eventStreamManager.IsRunning()); + return UI::EVENT_DONE; + }); + + buttonRow->Add(new Button("Zoom In"))->OnClick.Add([=](UI::EventParams &) { + ZoomAtCursor(2.0f); + return UI::EVENT_DONE; + }); + + buttonRow->Add(new Button("Zoom Out"))->OnClick.Add([=](UI::EventParams &) { + ZoomAtCursor(0.5f); + return UI::EVENT_DONE; + }); +} + +void EventProfilerView::ZoomAtCursor(float zoomAmount) { + // Zoom around the hover X + float fractionX = hoverX_ / bounds_.w; + + float oldTimeSpan = timeSpan_; + timeSpan_ *= 1.0 / zoomAmount; + + float diff = oldTimeSpan - timeSpan_; + + startTime_ += diff * fractionX; + // float delta = hoverTime_ - startTime_; + UpdateScale(); +} + +bool EventProfilerView::Key(const KeyInput &input) { + float zoomAmount = 1.0f; + + switch (input.keyCode) { + case NKCODE_EXT_MOUSEWHEEL_UP: + zoomAmount = 2.0f; + break; + case NKCODE_EXT_MOUSEWHEEL_DOWN: + zoomAmount = 0.5f; + break; + } + + if (zoomAmount != 1.0f) { + ZoomAtCursor(zoomAmount); + } + + return AnchorLayout::Key(input); +} + +void EventProfilerView::Touch(const TouchInput &input) { + AnchorLayout::Touch(input); + + if ((input.flags & TOUCH_DOWN) && input.id == 0) { + dragging_ = true; + dragStartX_ = input.x; + dragStartY_ = input.y; + dragStartScrollY_ = scrollY_; + dragStartTime_ = startTime_; + hoverX_ = input.x; + hoverY_ = input.y; + } + + if (input.flags & (TOUCH_MOVE | TOUCH_HOVER_MOVE)) { + if (dragging_) { + double dx = input.x - dragStartX_; + double dy = input.y - dragStartY_; + + startTime_ = dragStartTime_ - dx / secondsToPixelsScale_; + scrollY_ = dragStartScrollY_ + dy; + } else { + hoverX_ = input.x; + hoverY_ = input.y; + hoverTime_ = startTime_ + hoverX_ / secondsToPixelsScale_; + hoverStream_ = (hoverY_ - scrollY_) / streamHeight_; + } + } + + if ((input.flags & TOUCH_UP) && input.id == 0) { + dragging_ = false; + } +} + +void EventProfilerView::UpdateScale() { + secondsToPixelsScale_ = bounds_.w / timeSpan_; +} + +void EventProfilerView::Update() { + AnchorLayout::Update(); + + if (g_eventStreamManager.IsRunning() && !dragging_) { + // Scroll to the current time, put it exactly on the right edge of the screen. + Instant now = Instant::Now(); + startTime_ = now.ToSeconds() - timeSpan_; + } + + if (hoverStream_ >= 0 && hoverStream_ < g_eventStreamManager.NumStreams()) { + hoverEvent_ = g_eventStreamManager.GetByIndex(hoverStream_)->GetEventIdAt(Instant::FromSeconds(hoverTime_)); + } + + UpdateScale(); +} + +void EventProfilerView::Draw(UIContext &ui) { + AnchorLayout::Draw(ui); + + const Bounds &bounds = ui.GetBounds(); + + uint32_t frameColors[3] = { 0xFF5060FF, 0xFFFF8030, 0xFF30CC50 }; + + std::vector streams = g_eventStreamManager.GetAll(); + + double y = scrollY_; + + ui.SetFontScale(0.4f, 0.4f); + + Instant startTime = Instant::FromSeconds(startTime_); + Instant endTime = startTime.AddSeconds(timeSpan_); + + char temp[256]; + + EventStream::Event hoveredEvent{}; + + // Draw millisecond ticks at the top. + double tickSize = 0.001; // 1 ms + int tickCount = (int)(timeSpan_ / tickSize) + 2; + + // If there are too many ticks, keep every 10th. + while (tickCount >= bounds_.w / 10.0) { + tickSize *= 10.0; + tickCount /= 10; + } + + double firstTickTime = startTime.ToSeconds() - fmod(startTime.ToSeconds(), tickSize); + + for (int i = 0; i < tickCount; i++) { + double t = firstTickTime + i * tickSize; + double x = (t - startTime_) * secondsToPixelsScale_; + ui.VLine(x, y - 5.0, y, 0xFFFFFFFF); + } + + for (size_t i = 0; i < streams.size(); i++) { + int64_t firstEventId = -1; + std::vector events = streams[i]->GetEventRange(startTime, endTime, &firstEventId); + + if (events.empty()) { + continue; + } + + double lastTime = events.back().endTime.ToSeconds(); + + // Background + Bounds hoverStreamBounds; + hoverStreamBounds.y = y; + hoverStreamBounds.h = streamHeight_; + hoverStreamBounds.x = 0.0f; + hoverStreamBounds.w = bounds.w; + // Highlight the hovered stream. + bool hoverStream = hoverStream_ == i; + UI::Drawable color(hoverStream ? 0x50FFFFFF : 0x50000000); + ui.FillRect(color, hoverStreamBounds); + + for (size_t e = 0; e < events.size(); e++) { + const EventStream::Event &event = events[e]; + int64_t eventId = firstEventId + e; + + bool hover = hoverStream && hoverEvent_ == eventId && hoverTime_ <= event.endTime.ToSeconds(); + if (hover) { + hoveredEvent = event; + } + + float inset = 4.0f; + u32 alphaMask = 0xFFFFFFFF; + if (event.type == EventStream::EventType::BLOCK) { + inset = 12.0f; + alphaMask = 0xC0FFFFFF; + } + + Bounds rectBounds; + rectBounds.y = y + inset; + rectBounds.x = secondsToPixelsScale_ * (event.startTime.ToSeconds() - startTime_); + rectBounds.w = secondsToPixelsScale_ * (event.startTime.DifferenceInSeconds(event.endTime)); + rectBounds.h = streamHeight_ - inset * 2; + + if (hover) { + Bounds outlineRectBounds = rectBounds.Expand(2.0f, 2.0f); + ui.FillRect(UI::Drawable(0xFFFFFFFF & alphaMask), outlineRectBounds); + } + + UI::Drawable color(frameColors[event.frameId % ARRAY_SIZE(frameColors)] & alphaMask); + ui.FillRect(color, rectBounds); + + snprintf(temp, sizeof(temp), "%s %d", event.name, (int)event.frameId); + ui.DrawTextRect(temp, rectBounds, 0xFFFFFFFF, ALIGN_VCENTER | FLAG_DYNAMIC_ASCII); + } + + y += streamHeight_; + } + + // Draw a vertical line at the hover time, if paused. + if (!g_eventStreamManager.IsRunning()) { + float secsIntoView = (hoverTime_ - startTime_); + ui.VLine(secsIntoView * secondsToPixelsScale_, scrollY_, y, 0xCCFFFFFF); + } + + ui.Flush(); + + // Draw info about the hovered item at the bottom. + if (hoveredEvent.name) { + EventStream *stream = g_eventStreamManager.GetByIndex(hoverStream_); + if (stream) { + snprintf(temp, sizeof(temp), "%s (%d): %0.2fms\n%s", + hoveredEvent.name, (int)hoveredEvent.frameId, hoveredEvent.startTime.DifferenceInSeconds(hoveredEvent.endTime) * 1000.0, + stream->Identifier()); + ui.DrawTextShadow(temp, hoverX_, y, 0xFFFFFFFF); + } + } + + ui.SetFontScale(1.0f, 1.0f); +} diff --git a/UI/ProfilerDraw.h b/UI/ProfilerDraw.h index 4de6d4c806..386892aa84 100644 --- a/UI/ProfilerDraw.h +++ b/UI/ProfilerDraw.h @@ -1,9 +1,51 @@ #pragma once +#include "UI/View.h" +#include "UI/ViewGroup.h" + class UIContext; #ifdef USE_PROFILER void DrawProfile(UIContext &ui); -#endif \ No newline at end of file +#endif + +class EventProfilerView : public UI::AnchorLayout { +public: + EventProfilerView(UI::LayoutParams *layoutParams = nullptr); + void Draw(UIContext &dc) override; + void Update() override; + + bool Key(const KeyInput &input); + void Touch(const TouchInput &input); + +private: + void UpdateScale(); + void ZoomAtCursor(float zoomAmount); + + // Params + double streamHeight_ = 40.0f; + + // Currently zoomed range. + double startTime_ = 0.0; + double timeSpan_ = 0.1; + + float scrollY_ = 50.0f; + + double secondsToPixelsScale_ = 1.0f; + + bool dragging_ = false; + + double dragStartTime_ = 0.0f; + float dragStartScrollY_ = 0.0f; + double dragStartY_ = 0.0f; + float dragStartX_ = -1.0f; + // Hover + // Which stream the mouse is hovering above. + double hoverX_ = 0.0; + double hoverY_ = 0.0; + double hoverTime_ = 0.0; + int hoverStream_ = -1; + int64_t hoverEvent_ = -1; +}; diff --git a/Windows/MainWindow.cpp b/Windows/MainWindow.cpp index f483a55d9f..904209e509 100644 --- a/Windows/MainWindow.cpp +++ b/Windows/MainWindow.cpp @@ -695,6 +695,13 @@ namespace MainWindow touch.x = x; touch.y = y; NativeTouch(touch); + } else { + TouchInput touch; + touch.id = 0; + touch.flags = TOUCH_HOVER_MOVE; + touch.x = x; + touch.y = y; + NativeTouch(touch); } } break; diff --git a/android/jni/Android.mk b/android/jni/Android.mk index f317315e0a..96fff10265 100644 --- a/android/jni/Android.mk +++ b/android/jni/Android.mk @@ -177,6 +177,7 @@ EXEC_AND_LIB_FILES := \ $(SRC)/Common/Net/URL.cpp \ $(SRC)/Common/Net/WebsocketServer.cpp \ $(SRC)/Common/Profiler/Profiler.cpp \ + $(SRC)/Common/Profiler/EventStream.cpp \ $(SRC)/Common/System/Display.cpp \ $(SRC)/Common/Thread/ThreadUtil.cpp \ $(SRC)/Common/Thread/ThreadManager.cpp \ diff --git a/libretro/Makefile.common b/libretro/Makefile.common index f08bd45633..665a86a183 100644 --- a/libretro/Makefile.common +++ b/libretro/Makefile.common @@ -276,6 +276,7 @@ SOURCES_CXX += \ $(COMMONDIR)/Net/Sinks.cpp \ $(COMMONDIR)/Net/URL.cpp \ $(COMMONDIR)/Net/WebsocketServer.cpp \ + $(COMMONDIR)/Profiler/EventStream.cpp \ $(COMMONDIR)/Render/DrawBuffer.cpp \ $(COMMONDIR)/Render/TextureAtlas.cpp \ $(COMMONDIR)/Serialize/Serializer.cpp \ diff --git a/unittest/TestThreadManager.cpp b/unittest/TestThreadManager.cpp index 1457c587ed..77bbbf0853 100644 --- a/unittest/TestThreadManager.cpp +++ b/unittest/TestThreadManager.cpp @@ -96,7 +96,7 @@ void ThreadFunc() { bool TestMultithreadedScheduling() { g_atomicCounter = 0; - auto start = Instant::Now(); + double start = time_now_d(); std::vector threads; for (int i = 0; i < THREAD_COUNT; i++) { @@ -115,7 +115,7 @@ bool TestMultithreadedScheduling() { threads.clear(); - printf("Stress test elapsed: %0.2f", start.Elapsed()); + printf("Stress test elapsed: %0.2f", time_now_d() - start); return true; }