Implement a simple event profiler view.

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

Common/Common.vcxproj

@@ -466,6 +466,7 @@
     <ClInclude Include="Net\Sinks.h" />
     <ClInclude Include="Net\URL.h" />
     <ClInclude Include="Net\WebsocketServer.h" />
+    <ClInclude Include="Profiler\EventStream.h" />
     <ClInclude Include="Profiler\Profiler.h" />
     <ClInclude Include="Render\DrawBuffer.h" />
     <ClInclude Include="Render\TextureAtlas.h" />
@@ -886,6 +887,7 @@
     <ClCompile Include="Net\Sinks.cpp" />
     <ClCompile Include="Net\URL.cpp" />
     <ClCompile Include="Net\WebsocketServer.cpp" />
+    <ClCompile Include="Profiler\EventStream.cpp" />
     <ClCompile Include="Profiler\Profiler.cpp" />
     <ClCompile Include="Render\DrawBuffer.cpp" />
     <ClCompile Include="Render\TextureAtlas.cpp" />

Common/Common.vcxproj.filters

@@ -422,6 +422,9 @@
     <ClInclude Include="GPU\Vulkan\VulkanFrameData.h">
       <Filter>GPU\Vulkan</Filter>
     </ClInclude>
+    <ClInclude Include="Profiler\EventStream.h">
+      <Filter>Profiler</Filter>
+    </ClInclude>
   </ItemGroup>
   <ItemGroup>
     <ClCompile Include="ABI.cpp" />
@@ -797,6 +800,9 @@
     <ClCompile Include="GPU\Vulkan\VulkanFrameData.cpp">
       <Filter>GPU\Vulkan</Filter>
     </ClCompile>
+    <ClCompile Include="Profiler\EventStream.cpp">
+      <Filter>Profiler</Filter>
+    </ClCompile>
   </ItemGroup>
   <ItemGroup>
     <Filter Include="Crypto">

Common/GPU/Vulkan/VulkanDebug.cpp

@@ -93,4 +93,3 @@ VKAPI_ATTR VkBool32 VKAPI_CALL VulkanDebugUtilsCallback(
 	// keep that behavior here.
 	return false;
 }
-

Common/GPU/Vulkan/VulkanFrameData.h

@@ -6,6 +6,7 @@
 #include <condition_variable>
 
 #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);

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<VKRStep *> &steps) {
 }
 
 void VulkanQueueRunner::RunSteps(std::vector<VKRStep *> &steps, FrameData &frameData, FrameDataShared &frameDataShared) {
+	EventScope scope(frameData.renderThreadEvents, "run_steps", EventStream::EventType::COMPUTE);
+
 	QueueProfileContext *profile = frameData.profilingEnabled_ ? &frameData.profile : nullptr;
 
 	if (profile)

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<std::mutex> 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<std::mutex> lock(frameData.fenceMutex);
-		while (!frameData.readyForFence) {
-			frameData.fenceCondVar.wait(lock);
+		EventScope scope(mainThreadEvents_, "fence", EventStream::EventType::BLOCK);
+		{
+			std::unique_lock<std::mutex> 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;

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<VKRGraphicsPipeline *> pipelinesToCheck_;
+
+	EventStream *mainThreadEvents_;
+	EventStream *renderThreadEvents_;
 };

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,

Common/Profiler/EventStream.cpp

@@ -0,0 +1,114 @@
+#include <map>
+#include <memory>
+
+#include "EventStream.h"
+
+// Impl to avoid including <map> (or similar) in the header.
+struct EventStreamManagerImpl {
+	EventStream *Get(const char *identifier);
+
+	std::vector<std::unique_ptr<EventStream>> 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<EventStream>(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<EventStream *> EventStreamManager::GetAll() {
+	std::vector<EventStream *> vec;
+	for (auto &iter : impl_->streams) {
+		vec.push_back(iter.get());
+	}
+	return vec;
+}
+
+std::vector<EventStream::Event> 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<std::mutex> 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<EventStream::Event>();
+	}
+
+	*firstEventId = i;
+
+	std::vector<Event> 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<std::mutex> 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<std::mutex> 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;
+}

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 <vector>
+#include <mutex>
+
+#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<EventStream *> 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<std::mutex> 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<std::mutex> 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<Event> 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<Event> 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_;
+};

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_;

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) {

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

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<class T>
 	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<EventReturn(EventParams&)> func);
 
 private:

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 {

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.

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);

UI/DevScreens.h

@@ -216,4 +216,5 @@ private:
 };
 
 void DrawProfile(UIContext &ui);
+void DrawEventStreams(UIContext &ui);
 const char *GetCompilerABI();

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);

UI/ProfilerDraw.cpp

@@ -16,12 +16,18 @@
 // https://github.com/hrydgard/ppsspp and http://www.ppsspp.org/.
 
 #include <algorithm>
+#include <cmath>
 #include <inttypes.h>
 
+#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<EventStream *> 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<EventStream::Event> 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);
+}

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
+#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;
+};

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;

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 \

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 \

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<std::thread> 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;
 }